2017-09-17T00:43:23.322Z,1505609003.322 [Supervisor](DEBUG): Initializing supervisor.
2017-09-17T00:43:23.334Z,1505609003.334 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0
2017-09-17T00:43:23.334Z,1505609003.334 [SyncHandler](INFO): Protected caller Thread ID is 770
2017-09-17T00:43:23.335Z,1505609003.335 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2017-09-17T00:43:23.345Z,1505609003.345 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0
2017-09-17T00:43:23.346Z,1505609003.346 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 771
2017-09-17T00:43:23.349Z,1505609003.349 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2017-09-17T00:43:23.385Z,1505609003.385 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2017-09-17T00:43:23.397Z,1505609003.397 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0
2017-09-17T00:43:23.398Z,1505609003.398 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 772
2017-09-17T00:43:23.399Z,1505609003.399 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2017-09-17T00:43:23.409Z,1505609003.409 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0
2017-09-17T00:43:23.410Z,1505609003.410 [logger ThreadHandler](INFO): Protected caller Thread ID is 773
2017-09-17T00:43:23.413Z,1505609003.413 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2017-09-17T00:43:23.413Z,1505609003.413 [Supervisor](INFO): Looking for Config files in directory: Config/
2017-09-17T00:43:23.426Z,1505609003.426 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2017-09-17T00:43:23.834Z,1505609003.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2017-09-17T00:43:23.835Z,1505609003.835 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2017-09-17T00:43:23.977Z,1505609003.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2017-09-17T00:43:23.978Z,1505609003.978 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2017-09-17T00:43:24.361Z,1505609004.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2017-09-17T00:43:24.362Z,1505609004.362 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2017-09-17T00:43:24.514Z,1505609004.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2017-09-17T00:43:24.515Z,1505609004.515 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2017-09-17T00:43:24.602Z,1505609004.602 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2017-09-17T00:43:24.825Z,1505609004.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2017-09-17T00:43:24.826Z,1505609004.826 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2017-09-17T00:43:24.936Z,1505609004.936 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2017-09-17T00:43:24.937Z,1505609004.937 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2017-09-17T00:43:25.271Z,1505609005.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2017-09-17T00:43:25.272Z,1505609005.272 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2017-09-17T00:43:25.707Z,1505609005.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2017-09-17T00:43:25.708Z,1505609005.708 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2017-09-17T00:43:26.087Z,1505609006.087 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2017-09-17T00:43:26.087Z,1505609006.087 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2017-09-17T00:43:28.510Z,1505609008.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2017-09-17T00:43:28.512Z,1505609008.512 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2017-09-17T00:43:28.726Z,1505609008.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2017-09-17T00:43:28.727Z,1505609008.727 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2017-09-17T00:43:28.835Z,1505609008.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2017-09-17T00:43:28.835Z,1505609008.835 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2017-09-17T00:43:29.386Z,1505609009.386 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2017-09-17T00:43:29.387Z,1505609009.387 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2017-09-17T00:43:29.505Z,1505609009.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2017-09-17T00:43:29.507Z,1505609009.507 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2017-09-17T00:43:29.509Z,1505609009.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2017-09-17T00:43:29.810Z,1505609009.810 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2017-09-17T00:43:29.811Z,1505609009.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2017-09-17T00:43:29.920Z,1505609009.920 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2017-09-17T00:43:30.017Z,1505609010.017 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2017-09-17T00:43:30.128Z,1505609010.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2017-09-17T00:43:30.220Z,1505609010.220 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2017-09-17T00:43:30.359Z,1505609010.359 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2017-09-17T00:43:30.530Z,1505609010.530 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2017-09-17T00:43:30.633Z,1505609010.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2017-09-17T00:43:30.733Z,1505609010.733 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2017-09-17T00:43:39.969Z,1505609019.969 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2017-09-17T00:43:40.357Z,1505609020.357 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2017-09-17T00:43:40.438Z,1505609020.438 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2017-09-17T00:43:40.442Z,1505609020.442 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2017-09-17T00:43:40.614Z,1505609020.614 [SBIT](DEBUG): Construct Startup Built In Test.
2017-09-17T00:43:40.650Z,1505609020.650 [SBIT] Loaded
2017-09-17T00:43:40.651Z,1505609020.651 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2017-09-17T00:43:40.651Z,1505609020.651 [IBIT](DEBUG): Construct Initiated Built In Test.
2017-09-17T00:43:40.686Z,1505609020.686 [IBIT] Loaded
2017-09-17T00:43:40.687Z,1505609020.687 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2017-09-17T00:43:40.691Z,1505609020.691 [CBIT](DEBUG): Construct Continuous Built In Test.
2017-09-17T00:43:40.884Z,1505609020.884 [CBIT] Loaded
2017-09-17T00:43:40.885Z,1505609020.885 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2017-09-17T00:43:40.885Z,1505609020.885 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2017-09-17T00:43:40.886Z,1505609020.886 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2017-09-17T00:43:40.986Z,1505609020.986 [VerticalControl](DEBUG): Construct VerticalControl.
2017-09-17T00:43:41.106Z,1505609021.106 [VerticalControl] Loaded
2017-09-17T00:43:41.106Z,1505609021.106 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2017-09-17T00:43:41.107Z,1505609021.107 [HorizontalControl](DEBUG): Construct HorizontalControl.
2017-09-17T00:43:41.185Z,1505609021.185 [HorizontalControl] Loaded
2017-09-17T00:43:41.185Z,1505609021.185 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2017-09-17T00:43:41.186Z,1505609021.186 [SpeedControl](DEBUG): Construct SpeedControl.
2017-09-17T00:43:41.193Z,1505609021.193 [SpeedControl] Loaded
2017-09-17T00:43:41.193Z,1505609021.193 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2017-09-17T00:43:41.194Z,1505609021.194 [LoopControl](DEBUG): Construct LoopControl.
2017-09-17T00:43:41.195Z,1505609021.195 [LoopControl] Loaded
2017-09-17T00:43:41.195Z,1505609021.195 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2017-09-17T00:43:41.195Z,1505609021.195 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2017-09-17T00:43:41.196Z,1505609021.196 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2017-09-17T00:43:41.238Z,1505609021.238 [DepthRateCalculator] Loaded
2017-09-17T00:43:41.239Z,1505609021.239 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2017-09-17T00:43:41.245Z,1505609021.245 [PitchRateCalculator] Loaded
2017-09-17T00:43:41.245Z,1505609021.245 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2017-09-17T00:43:41.264Z,1505609021.264 [SpeedCalculator] Loaded
2017-09-17T00:43:41.264Z,1505609021.264 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2017-09-17T00:43:41.291Z,1505609021.291 [TempGradientCalculator] Loaded
2017-09-17T00:43:41.291Z,1505609021.291 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2017-09-17T00:43:41.310Z,1505609021.310 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2017-09-17T00:43:41.310Z,1505609021.310 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2017-09-17T00:43:41.316Z,1505609021.316 [YawRateCalculator] Loaded
2017-09-17T00:43:41.317Z,1505609021.317 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2017-09-17T00:43:41.317Z,1505609021.317 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2017-09-17T00:43:41.319Z,1505609021.319 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2017-09-17T00:43:41.459Z,1505609021.459 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2017-09-17T00:43:41.459Z,1505609021.459 [StratificationFrontDetector](DEBUG): (re)initializing
2017-09-17T00:43:41.459Z,1505609021.459 [StratificationFrontDetector] Loaded
2017-09-17T00:43:41.460Z,1505609021.460 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2017-09-17T00:43:41.460Z,1505609021.460 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2017-09-17T00:43:41.461Z,1505609021.461 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2017-09-17T00:43:41.746Z,1505609021.746 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2017-09-17T00:43:41.746Z,1505609021.746 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2017-09-17T00:43:41.884Z,1505609021.884 [DeadReckonUsingMultipleVelocitySources] Loaded
2017-09-17T00:43:41.884Z,1505609021.884 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2017-09-17T00:43:41.952Z,1505609021.952 [DeadReckonUsingSpeedCalculator] Loaded
2017-09-17T00:43:41.952Z,1505609021.952 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2017-09-17T00:43:41.973Z,1505609021.973 [NavChart] Loaded
2017-09-17T00:43:41.973Z,1505609021.973 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2017-09-17T00:43:41.978Z,1505609021.978 [UniversalFixResidualReporter] Loaded
2017-09-17T00:43:41.979Z,1505609021.979 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2017-09-17T00:43:41.979Z,1505609021.979 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2017-09-17T00:43:41.980Z,1505609021.980 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2017-09-17T00:43:42.010Z,1505609022.010 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2017-09-17T00:43:42.010Z,1505609022.010 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2017-09-17T00:43:42.227Z,1505609022.227 [Aanderaa_O2] Loaded
2017-09-17T00:43:42.227Z,1505609022.227 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2017-09-17T00:43:42.332Z,1505609022.332 [CTD_NeilBrown] Loaded
2017-09-17T00:43:42.333Z,1505609022.333 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2017-09-17T00:43:42.334Z,1505609022.334 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408134E0
2017-09-17T00:43:42.335Z,1505609022.335 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 856
2017-09-17T00:43:42.378Z,1505609022.378 [CTD_Seabird] Loaded
2017-09-17T00:43:42.378Z,1505609022.378 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2017-09-17T00:43:42.380Z,1505609022.380 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408434E0
2017-09-17T00:43:42.380Z,1505609022.380 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 857
2017-09-17T00:43:42.398Z,1505609022.398 [PAR_Licor] Loaded
2017-09-17T00:43:42.399Z,1505609022.399 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2017-09-17T00:43:42.456Z,1505609022.456 [WetLabsBB2FL] Loaded
2017-09-17T00:43:42.457Z,1505609022.457 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2017-09-17T00:43:42.458Z,1505609022.458 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408734E0
2017-09-17T00:43:42.458Z,1505609022.458 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 858
2017-09-17T00:43:42.459Z,1505609022.459 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2017-09-17T00:43:42.460Z,1505609022.460 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2017-09-17T00:43:43.109Z,1505609023.109 [DataOverHttps] Loaded
2017-09-17T00:43:43.109Z,1505609023.109 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2017-09-17T00:43:43.126Z,1505609023.126 [Depth_Keller] Loaded
2017-09-17T00:43:43.126Z,1505609023.126 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2017-09-17T00:43:43.132Z,1505609023.132 [DropWeight] Loaded
2017-09-17T00:43:43.132Z,1505609023.132 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2017-09-17T00:43:43.244Z,1505609023.244 [NAL9602] Loaded
2017-09-17T00:43:43.245Z,1505609023.245 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2017-09-17T00:43:43.256Z,1505609023.256 [Onboard] Loaded
2017-09-17T00:43:43.257Z,1505609023.257 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2017-09-17T00:43:43.265Z,1505609023.265 [Radio_Surface] Loaded
2017-09-17T00:43:43.266Z,1505609023.266 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2017-09-17T00:43:43.267Z,1505609023.267 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AF74E0
2017-09-17T00:43:43.267Z,1505609023.267 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 859
2017-09-17T00:43:43.439Z,1505609023.439 [DAT] Loaded
2017-09-17T00:43:43.440Z,1505609023.440 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2017-09-17T00:43:43.642Z,1505609023.642 [PNI_TCM] Loaded
2017-09-17T00:43:43.643Z,1505609023.643 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2017-09-17T00:43:43.717Z,1505609023.717 [Rowe_600LCM] Loaded
2017-09-17T00:43:43.717Z,1505609023.717 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2017-09-17T00:43:43.718Z,1505609023.718 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40B274E0
2017-09-17T00:43:43.719Z,1505609023.719 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 860
2017-09-17T00:43:46.224Z,1505609026.224 [BPC1] Loaded
2017-09-17T00:43:46.224Z,1505609026.224 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2017-09-17T00:43:46.224Z,1505609026.224 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2017-09-17T00:43:46.225Z,1505609026.225 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2017-09-17T00:43:46.358Z,1505609026.358 [BuoyancyServo] Loaded
2017-09-17T00:43:46.358Z,1505609026.358 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2017-09-17T00:43:46.373Z,1505609026.373 [ElevatorServo] Loaded
2017-09-17T00:43:46.373Z,1505609026.373 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2017-09-17T00:43:46.388Z,1505609026.388 [MassServo] Loaded
2017-09-17T00:43:46.388Z,1505609026.388 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2017-09-17T00:43:46.403Z,1505609026.403 [RudderServo] Loaded
2017-09-17T00:43:46.403Z,1505609026.403 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2017-09-17T00:43:46.418Z,1505609026.418 [ThrusterServo] Loaded
2017-09-17T00:43:46.418Z,1505609026.418 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2017-09-17T00:43:46.418Z,1505609026.418 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2017-09-17T00:43:46.419Z,1505609026.419 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2017-09-17T00:43:46.563Z,1505609026.563 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2017-09-17T00:43:46.563Z,1505609026.563 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2017-09-17T00:43:46.609Z,1505609026.609 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2017-09-17T00:43:46.614Z,1505609026.614 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2017-09-17T00:43:46.615Z,1505609026.615 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2017-09-17T00:43:46.626Z,1505609026.626 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2017-09-17T00:43:46.627Z,1505609026.627 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BFB4E0
2017-09-17T00:43:46.627Z,1505609026.627 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 861
2017-09-17T00:43:46.634Z,1505609026.634 [Supervisor](INFO): Main Thread ID is 765
2017-09-17T00:43:46.634Z,1505609026.634 [Supervisor](DEBUG): Running supervisor.
2017-09-17T00:43:46.635Z,1505609026.635 [CommandLine ThreadHandler](INFO): Handler Thread ID is 862
2017-09-17T00:43:46.638Z,1505609026.638 [controlThread ThreadHandler](INFO): Handler Thread ID is 863
2017-09-17T00:43:46.638Z,1505609026.638 [controlThread](DEBUG): Initializing ControlThread
2017-09-17T00:43:46.639Z,1505609026.639 [SBIT](INFO): Initialize SBIT Component.
2017-09-17T00:43:46.640Z,1505609026.640 [SBIT](IMPORTANT): git: 2017-08-02-115-g578c285
2017-09-17T00:43:46.640Z,1505609026.640 [SBIT](INFO): git hash: 578c285a2bbd310b0721fe6585a19844c60a5fcb
2017-09-17T00:43:46.643Z,1505609026.643 [SBIT](INFO): Kernel Reporting Different Release From Configuration.
Kernel Expected: 2.6.27.8
Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty
2017-09-17T00:43:46.643Z,1505609026.643 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016
2017-09-17T00:43:46.644Z,1505609026.644 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2017-09-17T00:43:46.645Z,1505609026.645 [IBIT](INFO): Initialize IBIT Component.
2017-09-17T00:43:46.645Z,1505609026.645 [CBIT](DEBUG): Initialize CBIT Component.
2017-09-17T00:43:46.646Z,1505609026.646 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2017-09-17T00:43:46.646Z,1505609026.646 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2017-09-17T00:43:46.647Z,1505609026.647 [logger ThreadHandler](INFO): Handler Thread ID is 864
2017-09-17T00:43:46.675Z,1505609026.675 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 865
2017-09-17T00:43:46.676Z,1505609026.676 [CTD_NeilBrown](INFO): Powering down
2017-09-17T00:43:46.719Z,1505609026.719 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 866
2017-09-17T00:43:46.720Z,1505609026.720 [CTD_Seabird](INFO): Initializing
2017-09-17T00:43:46.755Z,1505609026.755 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2017-09-17T00:43:46.758Z,1505609026.758 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2017-09-17T00:43:46.759Z,1505609026.759 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2017-09-17T00:43:46.759Z,1505609026.759 [LoopControl](DEBUG): Initialize LoopControlComponent.
2017-09-17T00:43:46.760Z,1505609026.760 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-09-17T00:43:46.760Z,1505609026.760 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2017-09-17T00:43:46.760Z,1505609026.760 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2017-09-17T00:43:46.761Z,1505609026.761 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2017-09-17T00:43:46.762Z,1505609026.762 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2017-09-17T00:43:46.763Z,1505609026.763 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2017-09-17T00:43:46.764Z,1505609026.764 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-09-17T00:43:46.765Z,1505609026.765 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:43:46.765Z,1505609026.765 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:43:46.766Z,1505609026.766 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-09-17T00:43:46.767Z,1505609026.767 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:43:46.767Z,1505609026.767 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:43:46.767Z,1505609026.767 [NavChart](DEBUG): Initialize NavChart Navigation.
2017-09-17T00:43:46.768Z,1505609026.768 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2017-09-17T00:43:46.787Z,1505609026.787 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 868
2017-09-17T00:43:46.789Z,1505609026.789 [WetLabsBB2FL](INFO): Powering down
2017-09-17T00:43:46.811Z,1505609026.811 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2017-09-17T00:43:46.843Z,1505609026.843 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 869
2017-09-17T00:43:46.871Z,1505609026.871 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 870
2017-09-17T00:43:46.872Z,1505609026.872 [Rowe_600LCM](INFO): Initializing
2017-09-17T00:43:46.873Z,1505609026.873 [Rowe_600LCM](INFO): Checking LCM
2017-09-17T00:43:46.895Z,1505609026.895 [Radio_Surface](INFO): Powering up
2017-09-17T00:43:46.896Z,1505609026.896 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2017-09-17T00:43:46.941Z,1505609026.941 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 871
2017-09-17T00:43:46.949Z,1505609026.949 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2017-09-17T00:43:46.949Z,1505609026.949 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2017-09-17T00:43:46.950Z,1505609026.950 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2017-09-17T00:43:46.950Z,1505609026.950 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2017-09-17T00:43:46.950Z,1505609026.950 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2017-09-17T00:43:46.950Z,1505609026.950 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2017-09-17T00:43:46.950Z,1505609026.950 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2017-09-17T00:43:46.951Z,1505609026.951 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2017-09-17T00:43:46.951Z,1505609026.951 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2017-09-17T00:43:46.951Z,1505609026.951 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2017-09-17T00:43:46.951Z,1505609026.951 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2017-09-17T00:43:46.952Z,1505609026.952 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2017-09-17T00:43:46.952Z,1505609026.952 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2017-09-17T00:43:46.952Z,1505609026.952 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2017-09-17T00:43:46.952Z,1505609026.952 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2017-09-17T00:43:46.952Z,1505609026.952 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2017-09-17T00:43:47.064Z,1505609027.064 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-09-17T00:43:47.064Z,1505609027.064 [CTD_Seabird](INFO): Powering down
2017-09-17T00:43:47.108Z,1505609027.108 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2017-09-17T00:43:47.115Z,1505609027.115 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2017-09-17T00:43:47.348Z,1505609027.348 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2017-09-17T00:43:47.350Z,1505609027.350 [Default:A.Wait](DEBUG): Construct Wait.
2017-09-17T00:43:47.352Z,1505609027.352 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2017-09-17T00:43:47.416Z,1505609027.416 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2017-09-17T00:43:47.444Z,1505609027.444 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2017-09-17T00:43:47.451Z,1505609027.451 [Default:E.Execute](DEBUG): Construct Execute.
2017-09-17T00:43:47.577Z,1505609027.577 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Guidance="Tethys/Guidance"
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Sequence/>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2017-09-17T00:43:47.582Z,1505609027.582 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2017-09-17T00:43:47.685Z,1505609027.685 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2017-09-17T00:43:47.803Z,1505609027.803 [Rowe_600LCM](INFO): LCM OK
2017-09-17T00:43:47.803Z,1505609027.803 [Rowe_600LCM](INFO): Powering up
2017-09-17T00:43:47.972Z,1505609027.972 [DAT](INFO): Powering up
2017-09-17T00:43:47.972Z,1505609027.972 [DAT](DEBUG): Initializing DAT.
2017-09-17T00:43:48.248Z,1505609028.248 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:48.411Z,1505609028.411 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:48.582Z,1505609028.582 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-09-17T00:43:48.590Z,1505609028.590 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-09-17T00:43:48.622Z,1505609028.622 [ElevatorServo](DEBUG): Initializing EZServoServo.
2017-09-17T00:43:48.630Z,1505609028.630 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2017-09-17T00:43:48.641Z,1505609028.641 [MassServo](DEBUG): Initializing EZServoServo.
2017-09-17T00:43:48.642Z,1505609028.642 [MassServo](DEBUG): Initializing MassServo.
2017-09-17T00:43:48.681Z,1505609028.681 [RudderServo](DEBUG): Initializing EZServoServo.
2017-09-17T00:43:48.690Z,1505609028.690 [RudderServo](DEBUG): Initializing RudderServo.
2017-09-17T00:43:48.696Z,1505609028.696 [ThrusterServo](DEBUG): Initializing EZServoServo.
2017-09-17T00:43:48.702Z,1505609028.702 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2017-09-17T00:43:48.993Z,1505609028.993 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2017-09-17T00:43:48.993Z,1505609028.993 [DropWeight] Hardware Fault, FailCount= 1
2017-09-17T00:43:49.023Z,1505609029.023 [DropWeight](ERROR): Hardware Fault
2017-09-17T00:43:49.024Z,1505609029.024 [NAL9602](INFO): Powering up NAL9602
2017-09-17T00:43:49.119Z,1505609029.119 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:49.120Z,1505609029.120 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:49.467Z,1505609029.467 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2017-09-17T00:43:49.467Z,1505609029.467 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2017-09-17T00:43:49.467Z,1505609029.467 [BuoyancyServo] Communications Fault, FailCount= 1
2017-09-17T00:43:49.467Z,1505609029.467 [BuoyancyServo](ERROR): Communications Fault
2017-09-17T00:43:49.713Z,1505609029.713 [CommandLine](FAULT): Scheduling is paused
2017-09-17T00:43:49.713Z,1505609029.713 [CBIT](INFO): Critical error at 20170917T004348
2017-09-17T00:43:49.714Z,1505609029.714 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2017-09-17T00:43:49.717Z,1505609029.717 [CBIT](ERROR): Hardware Fault in component: DropWeight
2017-09-17T00:43:49.717Z,1505609029.717 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2017-09-17T00:43:49.718Z,1505609029.718 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2017-09-17T00:43:49.804Z,1505609029.804 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:49.806Z,1505609029.806 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:49.817Z,1505609029.817 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-09-17T00:43:49.818Z,1505609029.818 [BuoyancyServo](INFO): Powering down
2017-09-17T00:43:49.932Z,1505609029.932 [CBIT](INFO): Critical error at 20170917T004349
2017-09-17T00:43:50.229Z,1505609030.229 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:50.230Z,1505609030.230 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:50.645Z,1505609030.645 [Aanderaa_O2](INFO): Powering down
2017-09-17T00:43:50.841Z,1505609030.841 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:50.843Z,1505609030.843 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:51.002Z,1505609031.002 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:51.004Z,1505609031.004 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:51.370Z,1505609031.370 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-09-17T00:43:51.458Z,1505609031.458 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:51.460Z,1505609031.460 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:51.701Z,1505609031.701 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-09-17T00:43:51.942Z,1505609031.942 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:51.959Z,1505609031.959 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-17T00:43:52.129Z,1505609032.129 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2017-09-17T00:43:52.129Z,1505609032.129 [BuoyancyServo] No Fault, FailCount= 1
2017-09-17T00:43:52.423Z,1505609032.423 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-09-17T00:43:52.424Z,1505609032.424 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-09-17T00:43:52.425Z,1505609032.425 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-09-17T00:43:52.460Z,1505609032.460 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-09-17T00:43:52.461Z,1505609032.461 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-09-17T00:43:54.739Z,1505609034.739 [PNI_TCM](ERROR): CRC does not match. Expected:0x61927 got:0x1797
2017-09-17T00:43:59.552Z,1505609039.552 [PNI_TCM](ERROR): CRC does not match. Expected:0x48771 got:0x1287
2017-09-17T00:43:59.909Z,1505609039.909 [NAL9602](INFO): NAL9602 initialized
2017-09-17T00:44:00.348Z,1505609040.348 [DAT](DEBUG): 
Teledyne Benthos DAT-900 Series
MF Frequency Band
Directional Acoustic Transponder version 8.12.5
Sep 17 2017 00:40:55 
WARNING: battery low
Features enabled [Bearing]
CONNECT
2017-09-17T00:44:00.349Z,1505609040.349 [DAT](INFO): Got CONNECT
2017-09-17T00:44:00.360Z,1505609040.360 [DAT](INFO): entering command mode
2017-09-17T00:44:00.746Z,1505609040.746 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:01.145Z,1505609041.145 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:01.555Z,1505609041.555 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:01.925Z,1505609041.925 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:02.326Z,1505609042.326 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:02.745Z,1505609042.745 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:03.142Z,1505609043.142 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:03.538Z,1505609043.538 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:03.926Z,1505609043.926 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:04.332Z,1505609044.332 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:04.340Z,1505609044.340 [PNI_TCM](ERROR): CRC does not match. Expected:0x37560 got:0x42911
2017-09-17T00:44:04.771Z,1505609044.771 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:05.129Z,1505609045.129 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:05.529Z,1505609045.529 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:05.932Z,1505609045.932 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:06.335Z,1505609046.335 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:06.725Z,1505609046.725 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:07.125Z,1505609047.125 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:07.125Z,1505609047.125 [DAT](FAULT): Low Battery detected. Re-entering command mode
2017-09-17T00:44:08.385Z,1505609048.385 [DAT](DEBUG): >>> Watchdog: 0x0010 [ PM ]

Teledyne Benthos DAT-900 Series
MF Frequency Band
Directional Acoustic Transponder version 8.12.5
Sep 17 2017 00:41:02 
WARNING: battery low
Features enabled [Bearing]
WARNING: Modem reset during xmit; lowering xmit power level by 3 dB.
WARNING: Reduced xmit power level to 7 due to weak battery.
CONNECT
2017-09-17T00:44:08.385Z,1505609048.385 [DAT](INFO): Got CONNECT
2017-09-17T00:44:08.397Z,1505609048.397 [DAT](INFO): entering command mode
2017-09-17T00:44:08.745Z,1505609048.745 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-17T00:44:08.745Z,1505609048.745 [DAT](DEBUG): read user prompt 1: user:1>
2017-09-17T00:44:08.745Z,1505609048.745 [DAT](INFO): command mode acknowledged
2017-09-17T00:44:09.127Z,1505609049.127 [DAT](INFO): setting local address to 2
2017-09-17T00:44:09.528Z,1505609049.528 [DAT](DEBUG): checking for local address setting acknowledgment
2017-09-17T00:44:09.529Z,1505609049.529 [DAT](INFO): set local address to 2
2017-09-17T00:44:09.926Z,1505609049.926 [DAT](DEBUG): read user prompt 2: user:2>
2017-09-17T00:44:10.395Z,1505609050.395 [SBIT](IMPORTANT): Beginning Startup BIT
2017-09-17T00:44:10.416Z,1505609050.416 [CBIT](IMPORTANT): Beginning ground fault scan
2017-09-17T00:44:21.077Z,1505609061.077 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.005093
CHAN A1 (24V): 4.792929
CHAN A2 (12V): -0.067424
CHAN A3 (5V): 0.000267
CHAN B0 (3.3V): 0.000085
CHAN B1 (3.15aV): -0.000426
CHAN B2 (3.15bV): -0.000285
CHAN B3 (GND): 0.000161
OPEN: -0.000488
Full Scale Calc: 4.765 mA, -1.589 mA
2017-09-17T00:45:04.203Z,1505609104.203 [SBIT](IMPORTANT): SBIT PASSED
2017-09-17T00:45:04.596Z,1505609104.596 [MissionManager](IMPORTANT): Started mission Startup
2017-09-17T00:45:04.596Z,1505609104.596 [Startup] Running Loop=1
2017-09-17T00:45:04.597Z,1505609104.597 [Startup](DEBUG): Aggregate::initialize Startup
2017-09-17T00:45:04.597Z,1505609104.597 [Startup:A.GoToSurface] Running Loop=1
2017-09-17T00:45:04.597Z,1505609104.597 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-09-17T00:45:04.606Z,1505609104.606 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-09-17T00:45:04.606Z,1505609104.606 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-09-17T00:45:04.607Z,1505609104.607 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-09-17T00:45:04.607Z,1505609104.607 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-09-17T00:45:04.607Z,1505609104.607 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-09-17T00:45:04.632Z,1505609104.632 [Startup:StartupSatComms] Running Loop=1
2017-09-17T00:45:04.632Z,1505609104.632 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2017-09-17T00:45:04.632Z,1505609104.632 [Startup:StartupSatComms:A] Running Loop=1
2017-09-17T00:45:05.001Z,1505609105.001 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2017-09-17T00:45:16.155Z,1505609116.155 [BPC1](ERROR): Failed to receive battery data
2017-09-17T00:45:16.155Z,1505609116.155 [BPC1] Communications Fault, FailCount= 1
2017-09-17T00:45:16.155Z,1505609116.155 [BPC1](ERROR): Communications Fault
2017-09-17T00:45:16.260Z,1505609116.260 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-17T00:45:17.458Z,1505609117.458 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:45:17.459Z,1505609117.459 [BPC1] No Fault, FailCount= 1
2017-09-17T00:45:33.473Z,1505609133.473 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003907
2017-09-17T00:45:48.062Z,1505609148.062 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-09-17T00:45:48.062Z,1505609148.062 [Rowe_600LCM] Communications Fault, FailCount= 1
2017-09-17T00:45:48.062Z,1505609148.062 [Rowe_600LCM](ERROR): Communications Fault
2017-09-17T00:45:48.374Z,1505609148.374 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s.
2017-09-17T00:45:48.407Z,1505609148.407 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-09-17T00:45:48.467Z,1505609148.467 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-09-17T00:45:48.570Z,1505609148.570 [Rowe_600LCM](INFO): Powering down
2017-09-17T00:45:48.752Z,1505609148.752 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s.
2017-09-17T00:45:49.149Z,1505609149.149 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-09-17T00:45:49.550Z,1505609149.550 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-09-17T00:45:49.908Z,1505609149.908 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-09-17T00:45:49.948Z,1505609149.948 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-09-17T00:45:49.948Z,1505609149.948 [Rowe_600LCM] No Fault, FailCount= 1
2017-09-17T00:45:50.178Z,1505609150.178 [Rowe_600LCM](INFO): Initializing
2017-09-17T00:45:50.178Z,1505609150.178 [Rowe_600LCM](INFO): Checking LCM
2017-09-17T00:45:50.178Z,1505609150.178 [Rowe_600LCM](INFO): LCM OK
2017-09-17T00:45:50.179Z,1505609150.179 [Rowe_600LCM](INFO): Powering up
2017-09-17T00:45:50.309Z,1505609150.309 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-09-17T00:45:50.713Z,1505609150.713 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-09-17T00:45:51.129Z,1505609151.129 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-09-17T00:45:51.512Z,1505609151.512 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-09-17T00:45:51.926Z,1505609151.926 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-09-17T00:45:52.326Z,1505609152.326 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-09-17T00:45:52.701Z,1505609152.701 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-09-17T00:45:53.131Z,1505609153.131 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-09-17T00:45:53.530Z,1505609153.530 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-09-17T00:45:53.933Z,1505609153.933 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-09-17T00:45:54.336Z,1505609154.336 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-09-17T00:45:54.403Z,1505609154.403 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-09-17T00:45:54.507Z,1505609154.507 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-09-17T00:45:54.509Z,1505609154.509 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-09-17T00:45:54.510Z,1505609154.510 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-09-17T00:45:54.511Z,1505609154.511 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-09-17T00:45:54.714Z,1505609154.714 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-09-17T00:46:04.735Z,1505609164.735 [Startup:StartupSatComms:A](INFO): Timed out from 2017-09-17T00:45:04.6Z
2017-09-17T00:46:04.735Z,1505609164.735 [Startup:StartupSatComms:A] Stopped
2017-09-17T00:46:04.735Z,1505609164.735 [Startup:StartupSatComms:B] Running Loop=1
2017-09-17T00:46:05.119Z,1505609165.119 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-09-17T00:46:09.719Z,1505609169.719 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170917T002744/Courier0000.lzma
2017-09-17T00:46:10.476Z,1505609170.476 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002744/Courier0000.lzma.bak
2017-09-17T00:46:10.476Z,1505609170.476 [DataOverHttps](INFO): SBD MOMSN=5092445
2017-09-17T00:46:20.896Z,1505609180.896 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20170917T002957/Courier0000.lzma
2017-09-17T00:46:22.760Z,1505609182.760 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002957/Courier0000.lzma.bak
2017-09-17T00:46:22.760Z,1505609182.760 [DataOverHttps](INFO): SBD MOMSN=5092448
2017-09-17T00:46:32.247Z,1505609192.247 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20170917T002957/Courier0004.lzma
2017-09-17T00:46:32.649Z,1505609192.649 [BPC1](ERROR): Failed to parse message.
2017-09-17T00:46:32.649Z,1505609192.649 [BPC1](ERROR): Failed to parse bank B battery data
2017-09-17T00:46:32.649Z,1505609192.649 [BPC1] Data Fault, FailCount= 1
2017-09-17T00:46:32.650Z,1505609192.650 [BPC1](ERROR): Data Fault
2017-09-17T00:46:32.677Z,1505609192.677 [CBIT](ERROR): Data Fault in component: BPC1
2017-09-17T00:46:33.006Z,1505609193.006 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002957/Courier0004.lzma.bak
2017-09-17T00:46:33.020Z,1505609193.020 [DataOverHttps](INFO): SBD MOMSN=5092453
2017-09-17T00:46:33.899Z,1505609193.899 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:46:33.899Z,1505609193.899 [BPC1] No Fault, FailCount= 1
2017-09-17T00:46:42.609Z,1505609202.609 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170917T002957/Courier0008.lzma
2017-09-17T00:46:43.368Z,1505609203.368 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002957/Courier0008.lzma.bak
2017-09-17T00:46:43.368Z,1505609203.368 [DataOverHttps](INFO): SBD MOMSN=5092455
2017-09-17T00:46:47.657Z,1505609207.657 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:46:47.658Z,1505609207.658 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2017-09-17T00:46:47.658Z,1505609207.658 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-09-17T00:46:47.660Z,1505609207.660 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:46:47.660Z,1505609207.660 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2017-09-17T00:46:47.660Z,1505609207.660 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-09-17T00:46:47.738Z,1505609207.738 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-09-17T00:46:47.738Z,1505609207.738 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-09-17T00:46:47.885Z,1505609207.885 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-09-17T00:46:47.885Z,1505609207.885 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2017-09-17T00:46:47.886Z,1505609207.886 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-09-17T00:46:47.886Z,1505609207.886 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2017-09-17T00:46:48.236Z,1505609208.236 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-09-17T00:46:48.237Z,1505609208.237 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:46:48.238Z,1505609208.238 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:46:48.238Z,1505609208.238 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-09-17T00:46:48.239Z,1505609208.239 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:46:48.239Z,1505609208.239 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:46:53.098Z,1505609213.098 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20170917T004323/Courier0000.lzma
2017-09-17T00:46:53.881Z,1505609213.881 [DataOverHttps](INFO): Moved sent file to Logs/20170917T004323/Courier0000.lzma.bak
2017-09-17T00:46:53.881Z,1505609213.881 [DataOverHttps](INFO): SBD MOMSN=5092457
2017-09-17T00:46:53.952Z,1505609213.952 [PNI_TCM](ERROR): CRC does not match. Expected:0x34353 got:0x39274
2017-09-17T00:47:03.809Z,1505609223.809 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20170913T231033/Express0581.lzma
2017-09-17T00:47:04.559Z,1505609224.559 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0581.lzma.bak
2017-09-17T00:47:04.559Z,1505609224.559 [DataOverHttps](INFO): SBD MOMSN=5092462
2017-09-17T00:47:05.668Z,1505609225.668 [Startup:StartupSatComms:B](INFO): Timed out from 2017-09-17T00:46:04.7Z
2017-09-17T00:47:05.668Z,1505609225.668 [Startup:StartupSatComms:B] Stopped
2017-09-17T00:47:05.673Z,1505609225.673 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2017-09-17T00:47:05.673Z,1505609225.673 [Startup:StartupSatComms] Stopped
2017-09-17T00:47:05.673Z,1505609225.673 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2017-09-17T00:47:05.674Z,1505609225.674 [Startup](INFO): Completed Startup
2017-09-17T00:47:05.674Z,1505609225.674 [MissionManager](INFO): Startup is completed.
2017-09-17T00:47:05.674Z,1505609225.674 [MissionManager](INFO): Uninitializing Mission Startup
2017-09-17T00:47:05.675Z,1505609225.675 [Startup] Stopped
2017-09-17T00:47:05.675Z,1505609225.675 [Startup](DEBUG): Aggregate::uninitialize Startup
2017-09-17T00:47:05.675Z,1505609225.675 [Startup:A.GoToSurface] Stopped
2017-09-17T00:47:05.675Z,1505609225.675 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-09-17T00:47:05.799Z,1505609225.799 [MissionManager](IMPORTANT): Started mission Default
2017-09-17T00:47:05.800Z,1505609225.800 [Default] Running Loop=1
2017-09-17T00:47:05.800Z,1505609225.800 [Default](DEBUG): Aggregate::initialize Default
2017-09-17T00:47:05.800Z,1505609225.800 [Default:B.GoToSurface] Running Loop=1
2017-09-17T00:47:05.800Z,1505609225.800 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-09-17T00:47:05.800Z,1505609225.800 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-09-17T00:47:05.801Z,1505609225.801 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-09-17T00:47:05.805Z,1505609225.805 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-09-17T00:47:05.806Z,1505609225.806 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-09-17T00:47:05.806Z,1505609225.806 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-09-17T00:47:05.806Z,1505609225.806 [Default:A.Wait] Running Loop=1
2017-09-17T00:47:05.806Z,1505609225.806 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-09-17T00:47:18.824Z,1505609238.824 [Default:A.Wait](INFO): Done Waiting.
2017-09-17T00:47:18.825Z,1505609238.825 [Default:A.Wait] Stopped
2017-09-17T00:47:18.825Z,1505609238.825 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-09-17T00:47:19.217Z,1505609239.217 [Default:CheckIn] Running Loop=1
2017-09-17T00:47:19.217Z,1505609239.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-09-17T00:47:19.217Z,1505609239.217 [Default:CheckIn:Read_GPS] Running Loop=1
2017-09-17T00:47:19.637Z,1505609239.637 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2017-09-17T00:48:10.081Z,1505609290.081 [DataOverHttps](INFO): Sending 375 bytes from file Logs/20170913T231033/Express0585.lzma
2017-09-17T00:48:10.872Z,1505609290.872 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0585.lzma.bak
2017-09-17T00:48:10.873Z,1505609290.873 [DataOverHttps](INFO): SBD MOMSN=5092467
2017-09-17T00:48:23.742Z,1505609303.742 [BPC1](ERROR): Failed to parse bank A battery data
2017-09-17T00:48:23.742Z,1505609303.742 [BPC1] Data Fault, FailCount= 1
2017-09-17T00:48:23.742Z,1505609303.742 [BPC1](ERROR): Data Fault
2017-09-17T00:48:23.807Z,1505609303.807 [CBIT](ERROR): Data Fault in component: BPC1
2017-09-17T00:48:24.963Z,1505609304.963 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:48:24.964Z,1505609304.964 [BPC1] No Fault, FailCount= 1
2017-09-17T00:49:02.876Z,1505609342.876 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-09-17T00:49:09.949Z,1505609349.949 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-09-17T00:49:09.949Z,1505609349.949 [Rowe_600LCM] Communications Fault, FailCount= 2
2017-09-17T00:49:09.949Z,1505609349.949 [Rowe_600LCM](ERROR): Communications Fault
2017-09-17T00:49:10.066Z,1505609350.066 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.5 s old, using for 20.0 s.
2017-09-17T00:49:10.093Z,1505609350.093 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-09-17T00:49:10.216Z,1505609350.216 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-09-17T00:49:10.356Z,1505609350.356 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-09-17T00:49:10.458Z,1505609350.458 [Rowe_600LCM](INFO): Powering down
2017-09-17T00:49:10.630Z,1505609350.630 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.1 s old, using for 20.0 s.
2017-09-17T00:49:10.990Z,1505609350.990 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-09-17T00:49:11.399Z,1505609351.399 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-09-17T00:49:11.804Z,1505609351.804 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-09-17T00:49:11.841Z,1505609351.841 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-09-17T00:49:11.841Z,1505609351.841 [Rowe_600LCM] No Fault, FailCount= 2
2017-09-17T00:49:12.065Z,1505609352.065 [Rowe_600LCM](INFO): Initializing
2017-09-17T00:49:12.066Z,1505609352.066 [Rowe_600LCM](INFO): Checking LCM
2017-09-17T00:49:12.066Z,1505609352.066 [Rowe_600LCM](INFO): LCM OK
2017-09-17T00:49:12.066Z,1505609352.066 [Rowe_600LCM](INFO): Powering up
2017-09-17T00:49:12.201Z,1505609352.201 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-09-17T00:49:12.593Z,1505609352.593 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-09-17T00:49:12.997Z,1505609352.997 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-09-17T00:49:13.386Z,1505609353.386 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-09-17T00:49:13.771Z,1505609353.771 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-09-17T00:49:14.179Z,1505609354.179 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-09-17T00:49:14.584Z,1505609354.584 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-09-17T00:49:14.988Z,1505609354.988 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-09-17T00:49:15.390Z,1505609355.390 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2017-09-17T00:49:15.806Z,1505609355.806 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2017-09-17T00:49:16.211Z,1505609356.211 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2017-09-17T00:49:16.287Z,1505609356.287 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-09-17T00:49:16.387Z,1505609356.387 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-09-17T00:49:16.389Z,1505609356.389 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-09-17T00:49:16.389Z,1505609356.389 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-09-17T00:49:16.390Z,1505609356.390 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-09-17T00:49:16.595Z,1505609356.595 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2017-09-17T00:49:48.251Z,1505609388.251 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:49:48.251Z,1505609388.251 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2017-09-17T00:49:48.252Z,1505609388.252 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-09-17T00:49:48.263Z,1505609388.263 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:49:48.263Z,1505609388.263 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2017-09-17T00:49:48.263Z,1505609388.263 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-09-17T00:49:48.305Z,1505609388.305 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-09-17T00:49:48.306Z,1505609388.306 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-09-17T00:49:48.627Z,1505609388.627 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-09-17T00:49:48.628Z,1505609388.628 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2017-09-17T00:49:48.628Z,1505609388.628 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-09-17T00:49:48.628Z,1505609388.628 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2017-09-17T00:49:48.980Z,1505609388.980 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-09-17T00:49:48.981Z,1505609388.981 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:49:48.981Z,1505609388.981 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:49:48.982Z,1505609388.982 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-09-17T00:49:48.982Z,1505609388.982 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:49:48.982Z,1505609388.982 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:51:12.246Z,1505609472.246 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-09-17T00:51:12.246Z,1505609472.246 [Rowe_600LCM] Communications Fault, FailCount= 3
2017-09-17T00:51:12.246Z,1505609472.246 [Rowe_600LCM](ERROR): Communications Fault
2017-09-17T00:51:12.332Z,1505609472.332 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s.
2017-09-17T00:51:12.354Z,1505609472.354 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-09-17T00:51:12.651Z,1505609472.651 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-09-17T00:51:12.744Z,1505609472.744 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s.
2017-09-17T00:51:12.862Z,1505609472.862 [Rowe_600LCM](INFO): Powering down
2017-09-17T00:51:13.070Z,1505609473.070 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-09-17T00:51:13.468Z,1505609473.468 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-09-17T00:51:13.870Z,1505609473.870 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-09-17T00:51:14.274Z,1505609474.274 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-09-17T00:51:14.291Z,1505609474.291 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-09-17T00:51:14.291Z,1505609474.291 [Rowe_600LCM] No Fault, FailCount= 3
2017-09-17T00:51:14.466Z,1505609474.466 [Rowe_600LCM](INFO): Initializing
2017-09-17T00:51:14.467Z,1505609474.467 [Rowe_600LCM](INFO): Checking LCM
2017-09-17T00:51:14.467Z,1505609474.467 [Rowe_600LCM](INFO): LCM OK
2017-09-17T00:51:14.467Z,1505609474.467 [Rowe_600LCM](INFO): Powering up
2017-09-17T00:51:14.673Z,1505609474.673 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-09-17T00:51:15.067Z,1505609475.067 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.1 s old, using for 20.0 s.
2017-09-17T00:51:15.451Z,1505609475.451 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.5 s old, using for 20.0 s.
2017-09-17T00:51:15.854Z,1505609475.854 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-09-17T00:51:16.258Z,1505609476.258 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-09-17T00:51:16.663Z,1505609476.663 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-09-17T00:51:17.061Z,1505609477.061 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-09-17T00:51:17.456Z,1505609477.456 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-09-17T00:51:17.866Z,1505609477.866 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-09-17T00:51:18.279Z,1505609478.279 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-09-17T00:51:18.573Z,1505609478.573 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-09-17T00:51:18.656Z,1505609478.656 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-09-17T00:51:18.658Z,1505609478.658 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-09-17T00:51:18.659Z,1505609478.659 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-09-17T00:51:18.660Z,1505609478.660 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-09-17T00:51:18.756Z,1505609478.756 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.9 s old, using for 20.0 s.
2017-09-17T00:52:19.519Z,1505609539.519 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-09-17T00:47:19.2Z
2017-09-17T00:52:19.519Z,1505609539.519 [Default:CheckIn:Read_GPS] Stopped
2017-09-17T00:52:19.519Z,1505609539.519 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-09-17T00:52:19.912Z,1505609539.912 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-09-17T00:52:24.282Z,1505609544.282 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20170917T004323/Courier0004.lzma
2017-09-17T00:52:25.068Z,1505609545.068 [DataOverHttps](INFO): Moved sent file to Logs/20170917T004323/Courier0004.lzma.bak
2017-09-17T00:52:25.069Z,1505609545.069 [DataOverHttps](INFO): SBD MOMSN=5092478
2017-09-17T00:52:34.804Z,1505609554.804 [DataOverHttps](INFO): Sending 435 bytes from file Logs/20170913T231033/Express0589.lzma
2017-09-17T00:52:35.583Z,1505609555.583 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0589.lzma.bak
2017-09-17T00:52:35.583Z,1505609555.583 [DataOverHttps](INFO): SBD MOMSN=5092480
2017-09-17T00:52:40.839Z,1505609560.839 [BPC1](ERROR): Failed to parse bank B battery data
2017-09-17T00:52:40.840Z,1505609560.840 [BPC1] Data Fault, FailCount= 1
2017-09-17T00:52:40.840Z,1505609560.840 [BPC1](ERROR): Data Fault
2017-09-17T00:52:40.912Z,1505609560.912 [CBIT](ERROR): Data Fault in component: BPC1
2017-09-17T00:52:45.127Z,1505609565.127 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:52:45.128Z,1505609565.128 [BPC1] No Fault, FailCount= 1
2017-09-17T00:52:45.771Z,1505609565.771 [DataOverHttps](INFO): Sending 821 bytes from file Logs/20170913T231033/Express0593.lzma
2017-09-17T00:52:46.344Z,1505609566.344 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0593.lzma.bak
2017-09-17T00:52:46.345Z,1505609566.345 [DataOverHttps](INFO): SBD MOMSN=5092492
2017-09-17T00:52:51.633Z,1505609571.633 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:52:51.633Z,1505609571.633 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2017-09-17T00:52:51.634Z,1505609571.634 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-09-17T00:52:51.636Z,1505609571.636 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:52:51.636Z,1505609571.636 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2017-09-17T00:52:51.636Z,1505609571.636 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-09-17T00:52:51.692Z,1505609571.692 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-09-17T00:52:51.692Z,1505609571.692 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-09-17T00:52:51.826Z,1505609571.826 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-09-17T00:52:51.826Z,1505609571.826 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2017-09-17T00:52:51.826Z,1505609571.826 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-09-17T00:52:51.826Z,1505609571.826 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2017-09-17T00:52:52.176Z,1505609572.176 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-09-17T00:52:52.177Z,1505609572.177 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:52:52.177Z,1505609572.177 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:52:52.178Z,1505609572.178 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-09-17T00:52:52.178Z,1505609572.178 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:52:52.179Z,1505609572.179 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:53:00.849Z,1505609580.849 [DataOverHttps](INFO): Sending 694 bytes from file Logs/20170913T231033/Express0597.lzma
2017-09-17T00:53:01.584Z,1505609581.584 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0597.lzma.bak
2017-09-17T00:53:01.584Z,1505609581.584 [DataOverHttps](INFO): SBD MOMSN=5092521
2017-09-17T00:53:14.837Z,1505609594.837 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-09-17T00:53:14.837Z,1505609594.837 [Rowe_600LCM] Communications Fault, FailCount= 4
2017-09-17T00:53:14.837Z,1505609594.837 [Rowe_600LCM](ERROR): Communications Fault
2017-09-17T00:53:15.243Z,1505609595.243 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-09-17T00:53:15.488Z,1505609595.488 [Rowe_600LCM](INFO): Powering down
2017-09-17T00:53:18.214Z,1505609598.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.5 s old, using for 20.0 s.
2017-09-17T00:53:18.277Z,1505609598.277 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-09-17T00:53:18.277Z,1505609598.277 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-09-17T00:53:18.277Z,1505609598.277 [Rowe_600LCM] No Fault, FailCount= 4
2017-09-17T00:53:18.310Z,1505609598.310 [Rowe_600LCM](INFO): Initializing
2017-09-17T00:53:18.311Z,1505609598.311 [Rowe_600LCM](INFO): Checking LCM
2017-09-17T00:53:18.311Z,1505609598.311 [Rowe_600LCM](INFO): LCM OK
2017-09-17T00:53:18.311Z,1505609598.311 [Rowe_600LCM](INFO): Powering up
2017-09-17T00:53:18.361Z,1505609598.361 [DataOverHttps](INFO): Sending 786 bytes from file Logs/20170913T231033/Express0601.lzma
2017-09-17T00:53:18.490Z,1505609598.490 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.8 s old, using for 20.0 s.
2017-09-17T00:53:18.822Z,1505609598.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.1 s old, using for 20.0 s.
2017-09-17T00:53:19.137Z,1505609599.137 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0601.lzma.bak
2017-09-17T00:53:19.137Z,1505609599.137 [DataOverHttps](INFO): SBD MOMSN=5092555
2017-09-17T00:53:19.251Z,1505609599.251 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.6 s old, using for 20.0 s.
2017-09-17T00:53:20.522Z,1505609600.522 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.8 s old, using for 20.0 s.
2017-09-17T00:53:20.732Z,1505609600.732 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.1 s old, using for 20.0 s.
2017-09-17T00:53:22.602Z,1505609602.602 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-09-17T00:53:22.737Z,1505609602.737 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-09-17T00:53:22.739Z,1505609602.739 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-09-17T00:53:22.739Z,1505609602.739 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-09-17T00:53:22.740Z,1505609602.740 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-09-17T00:53:47.832Z,1505609627.832 [DataOverHttps](INFO): Sending 920 bytes from file Logs/20170913T231033/Express0605.lzma
2017-09-17T00:53:48.079Z,1505609628.079 [CBIT](DEBUG): EFC running - data check-sum false
2017-09-17T00:53:48.507Z,1505609628.507 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0605.lzma.bak
2017-09-17T00:53:48.507Z,1505609628.507 [DataOverHttps](INFO): SBD MOMSN=5092598
2017-09-17T00:54:07.010Z,1505609647.010 [DataOverHttps](INFO): Sending 805 bytes from file Logs/20170913T231033/Express0609.lzma
2017-09-17T00:54:07.415Z,1505609647.415 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-09-17T00:54:07.415Z,1505609647.415 [NAL9602] Data Fault, FailCount= 1
2017-09-17T00:54:07.415Z,1505609647.415 [NAL9602](ERROR): Data Fault
2017-09-17T00:54:07.581Z,1505609647.581 [CBIT](ERROR): Data Fault in component: NAL9602
2017-09-17T00:54:07.793Z,1505609647.793 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0609.lzma.bak
2017-09-17T00:54:07.793Z,1505609647.793 [DataOverHttps](INFO): SBD MOMSN=5092638
2017-09-17T00:54:07.819Z,1505609647.819 [NAL9602](INFO): Powering down
2017-09-17T00:54:09.409Z,1505609649.409 [CBIT](INFO): Clearing failed state for component NAL9602
2017-09-17T00:54:09.409Z,1505609649.409 [NAL9602] No Fault, FailCount= 1
2017-09-17T00:54:16.965Z,1505609656.965 [NAL9602](INFO): Powering up NAL9602
2017-09-17T00:54:17.021Z,1505609657.021 [BPC1](ERROR): Failed to receive battery data
2017-09-17T00:54:17.021Z,1505609657.021 [BPC1] Communications Fault, FailCount= 1
2017-09-17T00:54:17.021Z,1505609657.021 [BPC1](ERROR): Communications Fault
2017-09-17T00:54:17.114Z,1505609657.114 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-17T00:54:18.095Z,1505609658.095 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:54:18.095Z,1505609658.095 [BPC1] No Fault, FailCount= 1
2017-09-17T00:54:25.439Z,1505609665.439 [DataOverHttps](INFO): Sending 925 bytes from file Logs/20170913T231033/Express0613.lzma
2017-09-17T00:54:26.215Z,1505609666.215 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0613.lzma.bak
2017-09-17T00:54:26.215Z,1505609666.215 [DataOverHttps](INFO): SBD MOMSN=5092684
2017-09-17T00:54:35.215Z,1505609675.215 [NAL9602](INFO): NAL9602 initialized
2017-09-17T00:54:35.311Z,1505609675.311 [BPC1](ERROR): Failed to parse message.
2017-09-17T00:54:35.311Z,1505609675.311 [BPC1](ERROR): Failed to parse bank A battery data
2017-09-17T00:54:35.311Z,1505609675.311 [BPC1] Data Fault, FailCount= 2
2017-09-17T00:54:35.311Z,1505609675.311 [BPC1](ERROR): Data Fault
2017-09-17T00:54:35.418Z,1505609675.418 [CBIT](ERROR): Data Fault in component: BPC1
2017-09-17T00:54:36.365Z,1505609676.365 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:54:36.374Z,1505609676.374 [BPC1] No Fault, FailCount= 2
2017-09-17T00:54:44.948Z,1505609684.948 [DataOverHttps](INFO): Sending 804 bytes from file Logs/20170913T231033/Express0617.lzma
2017-09-17T00:54:45.733Z,1505609685.733 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0617.lzma.bak
2017-09-17T00:54:45.733Z,1505609685.733 [DataOverHttps](INFO): SBD MOMSN=5092723
2017-09-17T00:55:04.409Z,1505609704.409 [DataOverHttps](INFO): Sending 774 bytes from file Logs/20170913T231033/Express0621.lzma
2017-09-17T00:55:05.200Z,1505609705.200 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0621.lzma.bak
2017-09-17T00:55:05.200Z,1505609705.200 [DataOverHttps](INFO): SBD MOMSN=5092763
2017-09-17T00:55:18.833Z,1505609718.833 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-09-17T00:55:18.833Z,1505609718.833 [Rowe_600LCM] Communications Fault, FailCount= 5
2017-09-17T00:55:18.833Z,1505609718.833 [Rowe_600LCM](ERROR): Communications Fault
2017-09-17T00:55:19.237Z,1505609719.237 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-09-17T00:55:19.489Z,1505609719.489 [Rowe_600LCM](INFO): Powering down
2017-09-17T00:55:23.562Z,1505609723.562 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.5 s old, using for 20.0 s.
2017-09-17T00:55:23.638Z,1505609723.638 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-09-17T00:55:23.638Z,1505609723.638 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2017-09-17T00:55:23.679Z,1505609723.679 [DataOverHttps](INFO): Sending 937 bytes from file Logs/20170913T231033/Express0625.lzma
2017-09-17T00:55:23.789Z,1505609723.789 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.7 s old, using for 20.0 s.
2017-09-17T00:55:24.127Z,1505609724.127 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-09-17T00:55:24.462Z,1505609724.462 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0625.lzma.bak
2017-09-17T00:55:24.462Z,1505609724.462 [DataOverHttps](INFO): SBD MOMSN=5092804
2017-09-17T00:55:24.566Z,1505609724.566 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.5 s old, using for 20.0 s.
2017-09-17T00:55:25.821Z,1505609725.821 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.7 s old, using for 20.0 s.
2017-09-17T00:55:26.080Z,1505609726.080 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2017-09-17T00:55:33.214Z,1505609733.214 [BPC1](ERROR): Failed to receive battery data
2017-09-17T00:55:33.214Z,1505609733.214 [BPC1] Communications Fault, FailCount= 1
2017-09-17T00:55:33.214Z,1505609733.214 [BPC1](ERROR): Communications Fault
2017-09-17T00:55:33.279Z,1505609733.279 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2017-09-17T00:55:33.335Z,1505609733.335 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-17T00:55:33.443Z,1505609733.443 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.3 s old, using for 20.0 s.
2017-09-17T00:55:33.861Z,1505609733.861 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.8 s old, using for 20.0 s.
2017-09-17T00:55:34.256Z,1505609734.256 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.2 s old, using for 20.0 s.
2017-09-17T00:55:34.325Z,1505609734.325 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:55:34.325Z,1505609734.325 [BPC1] No Fault, FailCount= 1
2017-09-17T00:55:34.731Z,1505609734.731 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.6 s old, using for 20.0 s.
2017-09-17T00:55:41.607Z,1505609741.607 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170913T231033/Express0629.lzma
2017-09-17T00:55:42.407Z,1505609742.407 [DataOverHttps](INFO): Moved sent file to Logs/20170913T231033/Express0629.lzma.bak
2017-09-17T00:55:42.407Z,1505609742.407 [DataOverHttps](INFO): SBD MOMSN=5092850
2017-09-17T00:55:52.447Z,1505609752.447 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:55:52.447Z,1505609752.447 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2017-09-17T00:55:52.447Z,1505609752.447 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-09-17T00:55:52.455Z,1505609752.455 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-17T00:55:52.455Z,1505609752.455 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2017-09-17T00:55:52.455Z,1505609752.455 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-09-17T00:55:52.506Z,1505609752.506 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-09-17T00:55:52.521Z,1505609752.521 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-09-17T00:55:52.863Z,1505609752.863 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-09-17T00:55:52.863Z,1505609752.863 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2017-09-17T00:55:52.864Z,1505609752.864 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-09-17T00:55:52.864Z,1505609752.864 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2017-09-17T00:55:53.240Z,1505609753.240 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-09-17T00:55:53.240Z,1505609753.240 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:55:53.240Z,1505609753.240 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:55:53.241Z,1505609753.241 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-09-17T00:55:53.242Z,1505609753.242 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-09-17T00:55:53.242Z,1505609753.242 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-09-17T00:56:00.320Z,1505609760.320 [BPC1](ERROR): Failed to receive battery data
2017-09-17T00:56:00.320Z,1505609760.320 [BPC1] Communications Fault, FailCount= 2
2017-09-17T00:56:00.321Z,1505609760.321 [BPC1](ERROR): Communications Fault
2017-09-17T00:56:00.387Z,1505609760.387 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.9 s old, using for 20.0 s.
2017-09-17T00:56:00.432Z,1505609760.432 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-17T00:56:00.456Z,1505609760.456 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170917T002744/Express0001.lzma
2017-09-17T00:56:00.544Z,1505609760.544 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.1 s old, using for 20.0 s.
2017-09-17T00:56:00.944Z,1505609760.944 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.5 s old, using for 20.0 s.
2017-09-17T00:56:01.254Z,1505609761.254 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002744/Express0001.lzma.bak
2017-09-17T00:56:01.254Z,1505609761.254 [DataOverHttps](INFO): SBD MOMSN=5092852
2017-09-17T00:56:01.348Z,1505609761.348 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.9 s old, using for 20.0 s.
2017-09-17T00:56:01.402Z,1505609761.402 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:56:01.402Z,1505609761.402 [BPC1] No Fault, FailCount= 2
2017-09-17T00:56:02.900Z,1505609762.900 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.5 s old, using for 20.0 s.
2017-09-17T00:56:03.104Z,1505609763.104 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.7 s old, using for 20.0 s.
2017-09-17T00:56:10.309Z,1505609770.309 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.9 s old, using for 20.0 s.
2017-09-17T00:56:10.517Z,1505609770.517 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.1 s old, using for 20.0 s.
2017-09-17T00:56:10.915Z,1505609770.915 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.5 s old, using for 20.0 s.
2017-09-17T00:56:11.333Z,1505609771.333 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.9 s old, using for 20.0 s.
2017-09-17T00:56:11.699Z,1505609771.699 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.3 s old, using for 20.0 s.
2017-09-17T00:56:12.102Z,1505609772.102 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.7 s old, using for 20.0 s.
2017-09-17T00:56:19.554Z,1505609779.554 [DataOverHttps](INFO): Sending 709 bytes from file Logs/20170917T002957/Express0001.lzma
2017-09-17T00:56:20.340Z,1505609780.340 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002957/Express0001.lzma.bak
2017-09-17T00:56:20.341Z,1505609780.341 [DataOverHttps](INFO): SBD MOMSN=5092854
2017-09-17T00:56:38.192Z,1505609798.192 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20170917T002957/Express0005.lzma
2017-09-17T00:56:38.970Z,1505609798.970 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002957/Express0005.lzma.bak
2017-09-17T00:56:38.970Z,1505609798.970 [DataOverHttps](INFO): SBD MOMSN=5092867
2017-09-17T00:56:47.805Z,1505609807.805 [BPC1](ERROR): Failed to receive battery data
2017-09-17T00:56:47.805Z,1505609807.805 [BPC1] Communications Fault, FailCount= 1
2017-09-17T00:56:47.805Z,1505609807.805 [BPC1](ERROR): Communications Fault
2017-09-17T00:56:47.902Z,1505609807.902 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-17T00:56:48.904Z,1505609808.904 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:56:48.904Z,1505609808.904 [BPC1] No Fault, FailCount= 1
2017-09-17T00:56:57.191Z,1505609817.191 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170917T002957/Express0009.lzma
2017-09-17T00:56:57.956Z,1505609817.956 [DataOverHttps](INFO): Moved sent file to Logs/20170917T002957/Express0009.lzma.bak
2017-09-17T00:56:57.956Z,1505609817.956 [DataOverHttps](INFO): SBD MOMSN=5092874
2017-09-17T00:57:15.793Z,1505609835.793 [BPC1](ERROR): Failed to receive battery data
2017-09-17T00:57:15.793Z,1505609835.793 [BPC1] Communications Fault, FailCount= 2
2017-09-17T00:57:15.793Z,1505609835.793 [BPC1](ERROR): Communications Fault
2017-09-17T00:57:15.902Z,1505609835.902 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-17T00:57:15.960Z,1505609835.960 [DataOverHttps](INFO): Sending 749 bytes from file Logs/20170917T004323/Express0001.lzma
2017-09-17T00:57:16.718Z,1505609836.718 [DataOverHttps](INFO): Moved sent file to Logs/20170917T004323/Express0001.lzma.bak
2017-09-17T00:57:16.718Z,1505609836.718 [DataOverHttps](INFO): SBD MOMSN=5092876
2017-09-17T00:57:16.871Z,1505609836.871 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-17T00:57:16.871Z,1505609836.871 [BPC1] No Fault, FailCount= 2
2017-09-17T00:57:34.100Z,1505609854.100 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20170917T004323/Express0005.lzma
2017-09-17T00:57:34.883Z,15