2018-08-17T20:30:03.389Z,1534537803.389 [Supervisor](DEBUG): Initializing supervisor.
2018-08-17T20:30:03.392Z,1534537803.392 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-17T20:30:03.392Z,1534537803.392 [SyncHandler](INFO): Protected caller Thread ID is 7069
2018-08-17T20:30:03.393Z,1534537803.393 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-17T20:30:03.394Z,1534537803.394 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-17T20:30:03.394Z,1534537803.394 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7070
2018-08-17T20:30:03.397Z,1534537803.397 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-17T20:30:03.409Z,1534537803.409 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-17T20:30:03.410Z,1534537803.410 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-17T20:30:03.411Z,1534537803.411 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7071
2018-08-17T20:30:03.411Z,1534537803.411 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-17T20:30:03.412Z,1534537803.412 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-17T20:30:03.413Z,1534537803.413 [logger ThreadHandler](INFO): Protected caller Thread ID is 7072
2018-08-17T20:30:03.415Z,1534537803.415 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-17T20:30:03.415Z,1534537803.415 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-17T20:30:03.417Z,1534537803.417 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-17T20:30:03.773Z,1534537803.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-17T20:30:03.774Z,1534537803.774 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-17T20:30:03.990Z,1534537803.990 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-17T20:30:03.991Z,1534537803.991 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-17T20:30:04.292Z,1534537804.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-17T20:30:04.292Z,1534537804.292 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-17T20:30:04.436Z,1534537804.436 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-17T20:30:04.437Z,1534537804.437 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-17T20:30:04.535Z,1534537804.535 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-17T20:30:04.536Z,1534537804.536 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-17T20:30:05.029Z,1534537805.029 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-17T20:30:05.030Z,1534537805.030 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-17T20:30:05.477Z,1534537805.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-17T20:30:05.478Z,1534537805.478 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-17T20:30:05.962Z,1534537805.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-17T20:30:05.963Z,1534537805.963 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-17T20:30:06.070Z,1534537806.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-17T20:30:06.071Z,1534537806.071 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-17T20:30:06.170Z,1534537806.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-17T20:30:06.170Z,1534537806.170 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-17T20:30:06.385Z,1534537806.385 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-17T20:30:06.386Z,1534537806.386 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-17T20:30:06.631Z,1534537806.631 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-17T20:30:06.631Z,1534537806.631 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-17T20:30:07.048Z,1534537807.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-17T20:30:07.049Z,1534537807.049 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-17T20:30:07.195Z,1534537807.195 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-17T20:30:07.196Z,1534537807.196 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-17T20:30:07.278Z,1534537807.278 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-08-17T20:30:07.279Z,1534537807.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-08-17T20:30:07.384Z,1534537807.384 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-08-17T20:30:07.507Z,1534537807.507 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-08-17T20:30:07.603Z,1534537807.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-08-17T20:30:07.689Z,1534537807.689 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-08-17T20:30:07.854Z,1534537807.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-08-17T20:30:08.040Z,1534537808.040 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-08-17T20:30:08.152Z,1534537808.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-08-17T20:30:09.049Z,1534537809.049 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-17T20:30:09.050Z,1534537809.050 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-08-17T20:30:09.134Z,1534537809.134 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-08-17T20:30:09.226Z,1534537809.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-08-17T20:30:09.330Z,1534537809.330 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-08-17T20:30:09.463Z,1534537809.463 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-08-17T20:30:09.464Z,1534537809.464 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-17T20:30:09.468Z,1534537809.468 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-17T20:30:09.711Z,1534537809.711 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-17T20:30:09.712Z,1534537809.712 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-17T20:30:09.754Z,1534537809.754 [DepthRateCalculator] Loaded
2018-08-17T20:30:09.754Z,1534537809.754 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-17T20:30:09.761Z,1534537809.761 [PitchRateCalculator] Loaded
2018-08-17T20:30:09.761Z,1534537809.761 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-17T20:30:09.778Z,1534537809.778 [SpeedCalculator] Loaded
2018-08-17T20:30:09.778Z,1534537809.778 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-17T20:30:09.801Z,1534537809.801 [TempGradientCalculator] Loaded
2018-08-17T20:30:09.802Z,1534537809.802 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-17T20:30:09.818Z,1534537809.818 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-17T20:30:09.819Z,1534537809.819 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-17T20:30:09.825Z,1534537809.825 [YawRateCalculator] Loaded
2018-08-17T20:30:09.825Z,1534537809.825 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-17T20:30:09.868Z,1534537809.868 [ElevatorOffsetCalculator] Loaded
2018-08-17T20:30:09.868Z,1534537809.868 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-17T20:30:09.869Z,1534537809.869 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-17T20:30:09.869Z,1534537809.869 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-17T20:30:10.020Z,1534537810.020 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-17T20:30:10.020Z,1534537810.020 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-17T20:30:10.021Z,1534537810.021 [StratificationFrontDetector] Loaded
2018-08-17T20:30:10.021Z,1534537810.021 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-17T20:30:10.022Z,1534537810.022 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-17T20:30:10.022Z,1534537810.022 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-17T20:30:10.135Z,1534537810.135 [BuoyancyServo] Loaded
2018-08-17T20:30:10.135Z,1534537810.135 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-17T20:30:10.151Z,1534537810.151 [ElevatorServo] Loaded
2018-08-17T20:30:10.152Z,1534537810.152 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-17T20:30:10.167Z,1534537810.167 [MassServo] Loaded
2018-08-17T20:30:10.168Z,1534537810.168 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-17T20:30:10.184Z,1534537810.184 [RudderServo] Loaded
2018-08-17T20:30:10.184Z,1534537810.184 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-17T20:30:10.199Z,1534537810.199 [ThrusterServo] Loaded
2018-08-17T20:30:10.200Z,1534537810.200 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-17T20:30:10.200Z,1534537810.200 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-17T20:30:10.201Z,1534537810.201 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-17T20:30:10.214Z,1534537810.214 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-17T20:30:10.214Z,1534537810.214 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-17T20:30:10.313Z,1534537810.313 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-17T20:30:10.313Z,1534537810.313 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-17T20:30:10.597Z,1534537810.597 [DataOverHttps] Loaded
2018-08-17T20:30:10.597Z,1534537810.597 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-17T20:30:10.612Z,1534537810.612 [Depth_Keller] Loaded
2018-08-17T20:30:10.612Z,1534537810.612 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-17T20:30:10.618Z,1534537810.618 [DropWeight] Loaded
2018-08-17T20:30:10.618Z,1534537810.618 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-17T20:30:10.722Z,1534537810.722 [NAL9602] Loaded
2018-08-17T20:30:10.723Z,1534537810.723 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-17T20:30:10.740Z,1534537810.740 [Onboard] Loaded
2018-08-17T20:30:10.740Z,1534537810.740 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-17T20:30:10.751Z,1534537810.751 [Radio_Surface] Loaded
2018-08-17T20:30:10.752Z,1534537810.752 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-17T20:30:10.753Z,1534537810.753 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408854E0
2018-08-17T20:30:10.753Z,1534537810.753 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7155
2018-08-17T20:30:10.803Z,1534537810.803 [PNI_TCM] Loaded
2018-08-17T20:30:10.804Z,1534537810.804 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-17T20:30:10.868Z,1534537810.868 [Rowe_600LCM] Loaded
2018-08-17T20:30:10.868Z,1534537810.868 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-08-17T20:30:10.869Z,1534537810.869 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408B54E0
2018-08-17T20:30:10.870Z,1534537810.870 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 7156
2018-08-17T20:30:12.693Z,1534537812.693 [BPC1] Loaded
2018-08-17T20:30:12.694Z,1534537812.694 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-17T20:30:12.694Z,1534537812.694 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-17T20:30:12.695Z,1534537812.695 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-17T20:30:12.826Z,1534537812.826 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-17T20:30:12.849Z,1534537812.849 [SBIT] Loaded
2018-08-17T20:30:12.850Z,1534537812.850 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-17T20:30:12.850Z,1534537812.850 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-17T20:30:12.862Z,1534537812.862 [IBIT] Loaded
2018-08-17T20:30:12.863Z,1534537812.863 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-17T20:30:12.866Z,1534537812.866 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-17T20:30:13.024Z,1534537813.024 [CBIT] Loaded
2018-08-17T20:30:13.025Z,1534537813.025 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-17T20:30:13.025Z,1534537813.025 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-17T20:30:13.026Z,1534537813.026 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-17T20:30:13.362Z,1534537813.362 [Aanderaa_O2] Loaded
2018-08-17T20:30:13.363Z,1534537813.363 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-17T20:30:13.458Z,1534537813.458 [PAR_Licor] Loaded
2018-08-17T20:30:13.458Z,1534537813.458 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-17T20:30:13.526Z,1534537813.526 [WetLabsBB2FL] Loaded
2018-08-17T20:30:13.526Z,1534537813.526 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-17T20:30:13.527Z,1534537813.527 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409784E0
2018-08-17T20:30:13.528Z,1534537813.528 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7157
2018-08-17T20:30:13.578Z,1534537813.578 [WetLabsSeaOWL_UV_A] Loaded
2018-08-17T20:30:13.578Z,1534537813.578 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-08-17T20:30:13.579Z,1534537813.579 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409A84E0
2018-08-17T20:30:13.580Z,1534537813.580 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 7158
2018-08-17T20:30:13.580Z,1534537813.580 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-17T20:30:13.581Z,1534537813.581 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-17T20:30:13.651Z,1534537813.651 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-17T20:30:13.741Z,1534537813.741 [VerticalControl] Loaded
2018-08-17T20:30:13.741Z,1534537813.741 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-17T20:30:13.742Z,1534537813.742 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-17T20:30:13.804Z,1534537813.804 [HorizontalControl] Loaded
2018-08-17T20:30:13.805Z,1534537813.805 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-17T20:30:13.806Z,1534537813.806 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-17T20:30:13.807Z,1534537813.807 [SpeedControl] Loaded
2018-08-17T20:30:13.808Z,1534537813.808 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-17T20:30:13.808Z,1534537813.808 [LoopControl](DEBUG): Construct LoopControl.
2018-08-17T20:30:13.809Z,1534537813.809 [LoopControl] Loaded
2018-08-17T20:30:13.809Z,1534537813.809 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-17T20:30:13.810Z,1534537813.810 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-17T20:30:13.810Z,1534537813.810 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-17T20:30:13.835Z,1534537813.835 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-17T20:30:13.836Z,1534537813.836 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-17T20:30:13.930Z,1534537813.930 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-17T20:30:13.930Z,1534537813.930 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-17T20:30:13.947Z,1534537813.947 [NavChart] Loaded
2018-08-17T20:30:13.948Z,1534537813.948 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-17T20:30:13.952Z,1534537813.952 [UniversalFixResidualReporter] Loaded
2018-08-17T20:30:13.952Z,1534537813.952 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-17T20:30:13.953Z,1534537813.953 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-17T20:30:13.957Z,1534537813.957 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-17T20:30:13.958Z,1534537813.958 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-17T20:30:13.965Z,1534537813.965 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-17T20:30:13.966Z,1534537813.966 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A344E0
2018-08-17T20:30:13.966Z,1534537813.966 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7159
2018-08-17T20:30:13.971Z,1534537813.971 [Supervisor](INFO): Main Thread ID is 7068
2018-08-17T20:30:13.971Z,1534537813.971 [Supervisor](DEBUG): Running supervisor.
2018-08-17T20:30:13.972Z,1534537813.972 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7160
2018-08-17T20:30:13.974Z,1534537813.974 [controlThread ThreadHandler](INFO): Handler Thread ID is 7161
2018-08-17T20:30:13.974Z,1534537813.974 [controlThread](DEBUG): Initializing ControlThread
2018-08-17T20:30:13.975Z,1534537813.975 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-17T20:30:13.976Z,1534537813.976 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-17T20:30:13.976Z,1534537813.976 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-17T20:30:13.976Z,1534537813.976 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-17T20:30:13.977Z,1534537813.977 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-17T20:30:13.978Z,1534537813.978 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-17T20:30:13.978Z,1534537813.978 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-17T20:30:13.983Z,1534537813.983 [SBIT](INFO): Initialize SBIT Component.
2018-08-17T20:30:13.984Z,1534537813.984 [SBIT](IMPORTANT): git: 2018-08-02-6-ga51bce9
2018-08-17T20:30:13.984Z,1534537813.984 [SBIT](INFO): git hash: a51bce9544ae2943cfba4f0cf10c7b00e5392907
2018-08-17T20:30:13.985Z,1534537813.985 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-17T20:30:13.986Z,1534537813.986 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-08-17T20:30:13.987Z,1534537813.987 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-08-17T20:30:13.987Z,1534537813.987 [IBIT](INFO): Initialize IBIT Component.
2018-08-17T20:30:13.988Z,1534537813.988 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-17T20:30:13.989Z,1534537813.989 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-17T20:30:13.990Z,1534537813.990 [logger ThreadHandler](INFO): Handler Thread ID is 7162
2018-08-17T20:30:14.009Z,1534537814.009 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7163
2018-08-17T20:30:14.016Z,1534537814.016 [Radio_Surface](INFO): Powering up
2018-08-17T20:30:14.021Z,1534537814.021 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 7164
2018-08-17T20:30:14.022Z,1534537814.022 [Rowe_600LCM](INFO): Initializing
2018-08-17T20:30:14.022Z,1534537814.022 [Rowe_600LCM](INFO): Checking LCM
2018-08-17T20:30:14.031Z,1534537814.031 [Rowe_600LCM](INFO): LCM OK
2018-08-17T20:30:14.031Z,1534537814.031 [Rowe_600LCM](INFO): Powering up
2018-08-17T20:30:14.037Z,1534537814.037 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7165
2018-08-17T20:30:14.039Z,1534537814.039 [WetLabsBB2FL](INFO): Powering down
2018-08-17T20:30:14.065Z,1534537814.065 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 7166
2018-08-17T20:30:14.073Z,1534537814.073 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7167
2018-08-17T20:30:14.076Z,1534537814.076 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-08-17T20:30:14.076Z,1534537814.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-08-17T20:30:14.077Z,1534537814.077 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-08-17T20:30:14.077Z,1534537814.077 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-08-17T20:30:14.077Z,1534537814.077 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-08-17T20:30:14.078Z,1534537814.078 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-08-17T20:30:14.078Z,1534537814.078 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-08-17T20:30:14.078Z,1534537814.078 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-08-17T20:30:14.078Z,1534537814.078 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-08-17T20:30:14.078Z,1534537814.078 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-08-17T20:30:14.079Z,1534537814.079 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-08-17T20:30:14.079Z,1534537814.079 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-08-17T20:30:14.079Z,1534537814.079 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-08-17T20:30:14.079Z,1534537814.079 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-08-17T20:30:14.079Z,1534537814.079 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-08-17T20:30:14.079Z,1534537814.079 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-08-17T20:30:14.105Z,1534537814.105 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-17T20:30:14.107Z,1534537814.107 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-17T20:30:14.108Z,1534537814.108 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-17T20:30:14.108Z,1534537814.108 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-17T20:30:14.109Z,1534537814.109 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-17T20:30:14.110Z,1534537814.110 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-17T20:30:14.110Z,1534537814.110 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-17T20:30:14.111Z,1534537814.111 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-17T20:30:14.111Z,1534537814.111 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-17T20:30:14.112Z,1534537814.112 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-17T20:30:14.135Z,1534537814.135 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-17T20:30:14.159Z,1534537814.159 [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>


2018-08-17T20:30:14.160Z,1534537814.160 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-17T20:30:14.268Z,1534537814.268 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-17T20:30:14.269Z,1534537814.269 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-17T20:30:14.271Z,1534537814.271 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-17T20:30:14.318Z,1534537814.318 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-17T20:30:14.321Z,1534537814.321 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-17T20:30:14.338Z,1534537814.338 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-17T20:30:14.342Z,1534537814.342 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <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">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <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>


2018-08-17T20:30:14.353Z,1534537814.353 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-17T20:30:14.382Z,1534537814.382 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-17T20:30:14.439Z,1534537814.439 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-08-17T20:30:14.671Z,1534537814.671 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-08-17T20:30:14.777Z,1534537814.777 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:14.893Z,1534537814.893 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-17T20:30:14.902Z,1534537814.902 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-17T20:30:14.929Z,1534537814.929 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-17T20:30:14.937Z,1534537814.937 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-17T20:30:14.955Z,1534537814.955 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-17T20:30:14.960Z,1534537814.960 [MassServo](DEBUG): Initializing MassServo.
2018-08-17T20:30:14.986Z,1534537814.986 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-17T20:30:14.987Z,1534537814.987 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-17T20:30:15.022Z,1534537815.022 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-17T20:30:15.060Z,1534537815.060 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-17T20:30:15.517Z,1534537815.517 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:15.914Z,1534537815.914 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:16.275Z,1534537816.275 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:16.745Z,1534537816.745 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:17.121Z,1534537817.121 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:17.490Z,1534537817.490 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:18.001Z,1534537818.001 [Aanderaa_O2](INFO): Powering down
2018-08-17T20:30:18.123Z,1534537818.123 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-17T20:30:18.405Z,1534537818.405 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-17T20:30:18.544Z,1534537818.544 [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 9600 >& /dev/null &
2018-08-17T20:30:18.598Z,1534537818.598 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-17T20:30:18.599Z,1534537818.599 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-17T20:30:18.599Z,1534537818.599 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-17T20:30:37.540Z,1534537837.540 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-17T20:30:37.575Z,1534537837.575 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-17T20:30:41.024Z,1534537841.024 [NAL9602](INFO): Powering up NAL9602
2018-08-17T20:30:48.457Z,1534537848.457 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.003930
CHAN A1 (24V): 4.657929
CHAN A2 (12V): -0.001653
CHAN A3 (5V): -0.002031
CHAN B0 (3.3V): 0.000096
CHAN B1 (3.15aV): -0.000228
CHAN B2 (3.15bV): 4.767929
CHAN B3 (GND): -0.000310
OPEN: -0.000601
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-17T20:30:51.852Z,1534537851.852 [NAL9602](INFO): NAL9602 initialized
2018-08-17T20:31:31.169Z,1534537891.169 [SBIT](IMPORTANT): SBIT PASSED
2018-08-17T20:31:31.299Z,1534537891.299 [CommandLine](IMPORTANT): got command configSet list
2018-08-17T20:31:31.300Z,1534537891.300 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-17T20:31:31.301Z,1534537891.301 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2018-08-17T20:31:31.302Z,1534537891.302 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2018-08-17T20:31:31.573Z,1534537891.573 [MissionManager](IMPORTANT): Started mission Startup
2018-08-17T20:31:31.575Z,1534537891.575 [Startup] Running Loop=1
2018-08-17T20:31:31.575Z,1534537891.575 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-17T20:31:31.576Z,1534537891.576 [Startup:A.GoToSurface] Running Loop=1
2018-08-17T20:31:31.576Z,1534537891.576 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-17T20:31:31.590Z,1534537891.590 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-17T20:31:31.591Z,1534537891.591 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-17T20:31:31.592Z,1534537891.592 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-17T20:31:31.602Z,1534537891.602 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-17T20:31:31.603Z,1534537891.603 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-17T20:31:31.673Z,1534537891.673 [Startup:StartupSatComms] Running Loop=1
2018-08-17T20:31:31.674Z,1534537891.674 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-17T20:31:31.674Z,1534537891.674 [Startup:StartupSatComms:A] Running Loop=1
2018-08-17T20:31:31.997Z,1534537891.997 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-17T20:32:14.181Z,1534537934.181 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-17T20:32:14.181Z,1534537934.181 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-17T20:32:14.181Z,1534537934.181 [Rowe_600LCM](ERROR): Communications Fault
2018-08-17T20:32:14.432Z,1534537934.432 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-17T20:32:14.585Z,1534537934.585 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-17T20:32:15.269Z,1534537935.269 [Rowe_600LCM](INFO): Powering down
2018-08-17T20:32:16.758Z,1534537936.758 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-17T20:32:16.758Z,1534537936.758 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-17T20:32:16.885Z,1534537936.885 [Rowe_600LCM](INFO): Initializing
2018-08-17T20:32:16.886Z,1534537936.886 [Rowe_600LCM](INFO): Checking LCM
2018-08-17T20:32:16.886Z,1534537936.886 [Rowe_600LCM](INFO): LCM OK
2018-08-17T20:32:16.886Z,1534537936.886 [Rowe_600LCM](INFO): Powering up
2018-08-17T20:32:21.220Z,1534537941.220 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-17T20:32:21.351Z,1534537941.351 [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 9600 >& /dev/null &
2018-08-17T20:32:21.353Z,1534537941.353 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-17T20:32:21.353Z,1534537941.353 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-17T20:32:21.354Z,1534537941.354 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-17T20:32:31.976Z,1534537951.976 [Startup:StartupSatComms:A](INFO): Timed out from 2018-08-17T20:31:31.7Z
2018-08-17T20:32:31.976Z,1534537951.976 [Startup:StartupSatComms:A] Stopped
2018-08-17T20:32:31.985Z,1534537951.985 [Startup:StartupSatComms:B] Running Loop=1
2018-08-17T20:32:32.387Z,1534537952.387 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-17T20:32:56.815Z,1534537976.815 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:32:57.610Z,1534537977.610 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:33:14.398Z,1534537994.398 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-17T20:33:14.398Z,1534537994.398 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-08-17T20:33:14.398Z,1534537994.398 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-17T20:33:14.440Z,1534537994.440 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-17T20:33:14.840Z,1534537994.840 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-17T20:33:14.840Z,1534537994.840 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-08-17T20:33:15.206Z,1534537995.206 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-17T20:33:15.207Z,1534537995.207 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-17T20:33:15.208Z,1534537995.208 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-17T20:33:26.866Z,1534538006.866 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006367
2018-08-17T20:33:38.478Z,1534538018.478 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-17T20:32:31.0Z
2018-08-17T20:33:38.478Z,1534538018.478 [Startup:StartupSatComms:B] Stopped
2018-08-17T20:33:38.478Z,1534538018.478 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-17T20:33:38.478Z,1534538018.478 [Startup:StartupSatComms] Stopped
2018-08-17T20:33:38.478Z,1534538018.478 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-17T20:33:38.480Z,1534538018.480 [Startup](INFO): Completed Startup
2018-08-17T20:33:38.481Z,1534538018.481 [MissionManager](INFO): Startup is completed.
2018-08-17T20:33:38.481Z,1534538018.481 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-17T20:33:38.481Z,1534538018.481 [Startup] Stopped
2018-08-17T20:33:38.482Z,1534538018.482 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-17T20:33:38.482Z,1534538018.482 [Startup:A.GoToSurface] Stopped
2018-08-17T20:33:38.482Z,1534538018.482 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-17T20:33:38.564Z,1534538018.564 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20180817T202415/Courier0004.lzma
2018-08-17T20:33:38.695Z,1534538018.695 [MissionManager](IMPORTANT): Started mission Default
2018-08-17T20:33:38.696Z,1534538018.696 [Default] Running Loop=1
2018-08-17T20:33:38.696Z,1534538018.696 [Default](DEBUG): Aggregate::initialize Default
2018-08-17T20:33:38.696Z,1534538018.696 [Default:B.GoToSurface] Running Loop=1
2018-08-17T20:33:38.696Z,1534538018.696 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-17T20:33:38.702Z,1534538018.702 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-17T20:33:38.702Z,1534538018.702 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-17T20:33:38.703Z,1534538018.703 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-17T20:33:38.704Z,1534538018.704 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-17T20:33:38.704Z,1534538018.704 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-17T20:33:38.709Z,1534538018.709 [Default:A.Wait] Running Loop=1
2018-08-17T20:33:38.709Z,1534538018.709 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-17T20:33:39.345Z,1534538019.345 [DataOverHttps](INFO): Moved sent file to Logs/20180817T202415/Courier0004.lzma.bak
2018-08-17T20:33:39.346Z,1534538019.346 [DataOverHttps](INFO): SBD MOMSN=8429862
2018-08-17T20:33:51.793Z,1534538031.793 [Default:A.Wait](INFO): Done Waiting.
2018-08-17T20:33:51.794Z,1534538031.794 [Default:A.Wait] Stopped
2018-08-17T20:33:51.794Z,1534538031.794 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-17T20:33:52.170Z,1534538032.170 [Default:CheckIn] Running Loop=1
2018-08-17T20:33:52.170Z,1534538032.170 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-17T20:33:52.171Z,1534538032.171 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-17T20:33:52.572Z,1534538032.572 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-17T20:34:17.681Z,1534538057.681 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-17T20:34:17.681Z,1534538057.681 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-17T20:34:17.681Z,1534538057.681 [Rowe_600LCM](ERROR): Communications Fault
2018-08-17T20:34:17.784Z,1534538057.784 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-17T20:34:18.085Z,1534538058.085 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-17T20:34:18.324Z,1534538058.324 [Rowe_600LCM](INFO): Powering down
2018-08-17T20:34:19.751Z,1534538059.751 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-17T20:34:19.751Z,1534538059.751 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-17T20:34:19.941Z,1534538059.941 [Rowe_600LCM](INFO): Initializing
2018-08-17T20:34:19.941Z,1534538059.941 [Rowe_600LCM](INFO): Checking LCM
2018-08-17T20:34:19.942Z,1534538059.942 [Rowe_600LCM](INFO): LCM OK
2018-08-17T20:34:19.942Z,1534538059.942 [Rowe_600LCM](INFO): Powering up
2018-08-17T20:34:24.064Z,1534538064.064 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-17T20:34:24.220Z,1534538064.220 [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 9600 >& /dev/null &
2018-08-17T20:34:24.222Z,1534538064.222 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-17T20:34:24.223Z,1534538064.223 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-17T20:34:24.224Z,1534538064.224 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-17T20:35:55.295Z,1534538155.295 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-17T20:36:15.346Z,1534538175.346 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-17T20:36:15.346Z,1534538175.346 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-08-17T20:36:15.346Z,1534538175.346 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-17T20:36:15.375Z,1534538175.375 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-17T20:36:15.801Z,1534538175.801 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-17T20:36:15.801Z,1534538175.801 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-08-17T20:36:16.148Z,1534538176.148 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-17T20:36:16.148Z,1534538176.148 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-17T20:36:16.150Z,1534538176.150 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-17T20:36:20.689Z,1534538180.689 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-17T20:36:20.689Z,1534538180.689 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-17T20:36:20.689Z,1534538180.689 [Rowe_600LCM](ERROR): Communications Fault
2018-08-17T20:36:20.991Z,1534538180.991 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-17T20:36:21.093Z,1534538181.093 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-17T20:36:21.207Z,1534538181.207 [Rowe_600LCM](INFO): Powering down
2018-08-17T20:36:22.571Z,1534538182.571 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-17T20:36:22.571Z,1534538182.571 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-17T20:36:22.821Z,1534538182.821 [Rowe_600LCM](INFO): Initializing
2018-08-17T20:36:22.821Z,1534538182.821 [Rowe_600LCM](INFO): Checking LCM
2018-08-17T20:36:22.822Z,1534538182.822 [Rowe_600LCM](INFO): LCM OK
2018-08-17T20:36:22.822Z,1534538182.822 [Rowe_600LCM](INFO): Powering up
2018-08-17T20:36:27.071Z,1534538187.071 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-17T20:36:27.136Z,1534538187.136 [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 9600 >& /dev/null &
2018-08-17T20:36:27.137Z,1534538187.137 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-17T20:36:27.137Z,1534538187.137 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-17T20:36:27.138Z,1534538187.138 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-17T20:37:44.118Z,1534538264.118 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:44.914Z,1534538264.914 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:45.710Z,1534538265.710 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:46.506Z,1534538266.506 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:47.302Z,1534538267.302 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:48.098Z,1534538268.098 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:48.894Z,1534538268.894 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:49.690Z,1534538269.690 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:50.486Z,1534538270.486 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:51.282Z,1534538271.282 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:52.078Z,1534538272.078 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:52.874Z,1534538272.874 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:53.672Z,1534538273.672 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:54.466Z,1534538274.466 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:55.262Z,1534538275.262 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:56.060Z,1534538276.060 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:56.854Z,1534538276.854 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:57.650Z,1534538277.650 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:58.446Z,1534538278.446 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:37:59.242Z,1534538279.242 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:00.038Z,1534538280.038 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:00.834Z,1534538280.834 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:01.630Z,1534538281.630 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:02.426Z,1534538282.426 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:03.222Z,1534538283.222 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:04.018Z,1534538284.018 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:04.814Z,1534538284.814 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:05.610Z,1534538285.610 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:06.406Z,1534538286.406 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:07.202Z,1534538287.202 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:07.998Z,1534538287.998 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:08.794Z,1534538288.794 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:09.590Z,1534538289.590 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:09.814Z,1534538289.814 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-17T20:38:09.814Z,1534538289.814 [BPC1] Communications Fault, FailCount= 1
2018-08-17T20:38:09.814Z,1534538289.814 [BPC1](ERROR): Communications Fault
2018-08-17T20:38:09.870Z,1534538289.870 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-17T20:38:10.386Z,1534538290.386 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:11.059Z,1534538291.059 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-17T20:38:11.059Z,1534538291.059 [BPC1] No Fault, FailCount= 1
2018-08-17T20:38:11.182Z,1534538291.182 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:11.978Z,1534538291.978 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:12.774Z,1534538292.774 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:13.570Z,1534538293.570 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:14.366Z,1534538294.366 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:15.162Z,1534538295.162 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:15.958Z,1534538295.958 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:16.754Z,1534538296.754 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:17.550Z,1534538297.550 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:18.346Z,1534538298.346 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:19.142Z,1534538299.142 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:19.938Z,1534538299.938 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:20.734Z,1534538300.734 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:21.531Z,1534538301.531 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:22.326Z,1534538302.326 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:23.122Z,1534538303.122 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:23.513Z,1534538303.513 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-17T20:38:23.513Z,1534538303.513 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-17T20:38:23.513Z,1534538303.513 [Rowe_600LCM](ERROR): Communications Fault
2018-08-17T20:38:23.860Z,1534538303.860 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-17T20:38:23.917Z,1534538303.917 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-17T20:38:24.043Z,1534538304.043 [Rowe_600LCM](INFO): Powering down
2018-08-17T20:38:24.849Z,1534538304.849 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-17T20:38:24.849Z,1534538304.849 [Rowe_600LCM] Hardware Fault, FailCount= 4
2018-08-17T20:38:24.849Z,1534538304.849 [Rowe_600LCM](ERROR): Hardware Fault
2018-08-17T20:38:25.466Z,1534538305.466 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-17T20:38:25.466Z,1534538305.466 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-17T20:38:25.657Z,1534538305.657 [Rowe_600LCM](INFO): Initializing
2018-08-17T20:38:25.658Z,1534538305.658 [Rowe_600LCM](INFO): Checking LCM
2018-08-17T20:38:25.658Z,1534538305.658 [Rowe_600LCM](INFO): LCM OK
2018-08-17T20:38:25.658Z,1534538305.658 [Rowe_600LCM](INFO): Powering up
2018-08-17T20:38:29.871Z,1534538309.871 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-17T20:38:29.975Z,1534538309.975 [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 9600 >& /dev/null &
2018-08-17T20:38:29.976Z,1534538309.976 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-17T20:38:29.976Z,1534538309.976 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-17T20:38:29.977Z,1534538309.977 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-17T20:38:52.303Z,1534538332.303 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-17T20:33:52.2Z
2018-08-17T20:38:52.303Z,1534538332.303 [Default:CheckIn:Read_GPS] Stopped
2018-08-17T20:38:52.303Z,1534538332.303 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-17T20:38:52.714Z,1534538332.714 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-17T20:38:55.858Z,1534538335.858 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:56.654Z,1534538336.654 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-08-17T20:38:57.044Z,1534538337.044 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20180817T202844/Courier0000.lzma
2018-08-17T20:38:57.846Z,1534538337.846 [DataOverHttps](INFO): Moved sent file to Logs/20180817T202844/Courier0000.lzma.bak
2018-08-17T20:38:57.846Z,1534538337.846 [DataOverHttps](INFO): SBD MOMSN=8429873
2018-08-17T20:39:07.475Z,1534538347.475 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180817T203003/Courier0004.lzma
2018-08-17T20:39:08.272Z,1534538348.272 [DataOverHttps](INFO): Moved sent file to Logs/20180817T203003/Courier0004.lzma.bak
2018-08-17T20:39:08.272Z,1534538348.272 [DataOverHttps](INFO): SBD MOMSN=8429880
2018-08-17T20:39:18.194Z,1534538358.194 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-17T20:39:18.194Z,1534538358.194 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-08-17T20:39:18.194Z,1534538358.194 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-17T20:39:18.222Z,1534538358.222 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-17T20:39:18.248Z,1534538358.248 [DataOverHttps](INFO): Sending 383 bytes from file Logs/20180817T202415/Express0005.lzma
2018-08-17T20:39:18.385Z,1534538358.385 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-17T20:39:18.385Z,1534538358.385 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-08-17T20:39:18.701Z,1534538358.701 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-17T20:39:18.702Z,1534538358.702 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-17T20:39:18.702Z,1534538358.702 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-17T20:39:19.032Z,1534538359.032 [DataOverHttps](INFO): Moved sent file to Logs/20180817T202415/Express0005.lzma.bak
2018-08-17T20:39:19.033Z,1534538359.033 [DataOverHttps](INFO): SBD MOMSN=8429883
2018-08-17T20:39:28.770Z,1534538368.770 [DataOverHttps](INFO): Sending 667 bytes from file Logs/20180817T202844/Express0001.lzma
2018-08-17T20:39:29.568Z,1534538369.568 [DataOverHttps](INFO): Moved sent file to Logs/20180817T202844/Express0001.lzma.bak
2018-08-17T20:39:29.568Z,1534538369.568 [DataOverHttps](INFO): SBD MOMSN=8429899
2018-08-17T20:39:39.295Z,1534538379.295 [DataOverHttps](INFO): Sending 626 bytes from file Logs/20180817T203003/Express0001.lzma
2018-08-17T20:39:40.084Z,1534538380.084 [DataOverHttps](INFO): Moved sent file to Logs/20180817T203003/Express0001.lzma.bak
2018-08-17T20:39:40.085Z,1534538380.085 [DataOverHttps](INFO): SBD MOMSN=8429920
2018-08-17T20:39:49.836Z,1534538389.836 [DataOverHttps](INFO): Sending 306 bytes from file Logs/20180817T203003/Express0005.lzma
2018-08-17T20:39:50.624Z,1534538390.624 [DataOverHttps](INFO): Moved sent file to Logs/20180817T203003/Express0005.lzma.bak
2018-08-17T20:39:50.624Z,1534538390.624 [DataOverHttps](INFO): SBD MOMSN=8429934
2018-08-17T20:39:51.459Z,1534538391.459 [Default:CheckIn:Read_Iridium] Stopped
2018-08-17T20:39:51.459Z,1534538391.459 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-17T20:39:51.460Z,1534538391.460 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-17T20:40:26.261Z,1534538426.261 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-17T20:40:26.261Z,1534538426.261 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-17T20:40:26.261Z,1534538426.261 [Rowe_600LCM](ERROR): Communications Fault
2018-08-17T20:40:26.370Z,1534538426.370 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-17T20:40:26.371Z,1534538426.371 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-17T20:40:26.666Z,1534538426.666 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-17T20:40:26.912Z,1534538426.912 [Rowe_600LCM](INFO): Powering down
2018-08-17T20:40:55.030Z,1534538455.030 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-17T20:40:55.030Z,1534538455.030 [NAL9602] Data Fault, FailCount= 1
2018-08-17T20:40:55.030Z,1534538455.030 [NAL9602](ERROR): Data Fault
2018-08-17T20:40:55.126Z,1534538455.126 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-17T20:40:55.175Z,1534538455.175 [NAL9602](INFO): Powering down
2018-08-17T20:40:56.005Z,1534538456.005 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-17T20:40:56.005Z,1534538456.005 [NAL9602] No Fault, FailCount= 1
2018-08-17T20:41:25.543Z,1534538485.543 [NAL9602](INFO): Powering up NAL9602
2018-08-17T20:41:36.740Z,1534538496.740 [NAL9602](INFO): NAL9602 initialized
2018-08-17T20:42:18.872Z,1534538538.872 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-17T20:42:18.872Z,1534538538.872 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2018-08-17T20:42:18.872Z,1534538538.872 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-17T20:42:18.897Z,1534538538.897 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-17T20:42:19.273Z,1534538539.273 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-17T20:42:19.273Z,1534538539.273 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2018-08-17T20:42:19.668Z,1534538539.668 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-17T20:42:19.668Z,1534538539.668 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-17T20:42:19.669Z,1534538539.669 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-17T20:44:51.730Z,1534538691.730 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-17T20:44:51.731Z,1534538691.731 [Default:CheckIn:C.Wait] Stopped
2018-08-17T20:44:51.731Z,1534538691.731 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-17T20:44:51.731Z,1534538691.731 [Default:CheckIn:D] Running Loop=1
2018-08-17T20:44:52.131Z,1534538692.131 [Default:CheckIn:D] Stopped
2018-08-17T20:44:52.131Z,1534538692.131 [Default:CheckIn:E] Running Loop=1
2018-08-17T20:44:55.278Z,1534538695.278 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.223815 min 
2018-08-17T20:44:55.281Z,1534538695.281 [Default:CheckIn:E] Stopped
2018-08-17T20:44:55.282Z,1534538695.282 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-17T20:44:55.282Z,1534538695.282 [Default:CheckIn] Stopped
2018-08-17T20:44:55.282Z,1534538695.282 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-17T20:44:55.282Z,1534538695.282 [Default:CheckIn](INFO): Running loop #2
2018-08-17T20:44:55.282Z,1534538695.282 [Default:CheckIn] Running Loop=2
2018-08-17T20:44:55.282Z,1534538695.282 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-17T20:44:55.282Z,1534538695.282 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-17T20:45:19.794Z,1534538719.794 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-17T20:45:19.794Z,1534538719.794 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2018-08-17T20:45:19.794Z,1534538719.794 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-17T20:45:19.816Z,1534538719.816 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-17T20:45:20.212Z,1534538720.212 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-17T20:45:20.212Z,1534538720.212 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2018-08-17T20:45:20.561Z,1534538720.561 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-17T20:45:20.562Z,1534538720.562 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-17T20:45:20.562Z,1534538720.562 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-17T20:45:41.450Z,1534538741.450 [CommandLine](IMPORTANT): got command restart application
2018-08-17T20:45:42.453Z,1534538742.453 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-08-17T20:45:42.456Z,1534538742.456 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:42.457Z,1534538742.457 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.521Z,1534538742.521 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-08-17T20:45:42.521Z,1534538742.521 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.522Z,1534538742.522 [CommandLine](INFO): Join timeout helper Thread ID is 7224
2018-08-17T20:45:42.523Z,1534538742.523 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-08-17T20:45:42.524Z,1534538742.524 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.545Z,1534538742.545 [NavChartDb](INFO): Join timeout helper Thread ID is 7225
2018-08-17T20:45:42.637Z,1534538742.637 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:42.637Z,1534538742.637 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.641Z,1534538742.641 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-08-17T20:45:42.641Z,1534538742.641 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.641Z,1534538742.641 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 7226
2018-08-17T20:45:42.689Z,1534538742.689 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:42.690Z,1534538742.690 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.705Z,1534538742.705 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-08-17T20:45:42.705Z,1534538742.705 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.705Z,1534538742.705 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7227
2018-08-17T20:45:42.845Z,1534538742.845 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:42.845Z,1534538742.845 [WetLabsBB2FL](INFO): Powering down
2018-08-17T20:45:42.846Z,1534538742.846 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.865Z,1534538742.865 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-08-17T20:45:42.865Z,1534538742.865 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:42.865Z,1534538742.865 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 7228
2018-08-17T20:45:42.985Z,1534538742.985 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:42.985Z,1534538742.985 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-17T20:45:43.128Z,1534538743.128 [Rowe_600LCM](INFO): Powering down
2018-08-17T20:45:43.129Z,1534538743.129 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.142Z,1534538743.142 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-08-17T20:45:43.142Z,1534538743.142 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.143Z,1534538743.143 [Radio_Surface](INFO): Join timeout helper Thread ID is 7230
2018-08-17T20:45:43.357Z,1534538743.357 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:43.358Z,1534538743.358 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.374Z,1534538743.374 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-08-17T20:45:43.374Z,1534538743.374 [logger ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.374Z,1534538743.374 [logger](INFO): Join timeout helper Thread ID is 7231
2018-08-17T20:45:43.389Z,1534538743.389 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:43.389Z,1534538743.389 [logger ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.394Z,1534538743.394 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-08-17T20:45:43.394Z,1534538743.394 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.394Z,1534538743.394 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-08-17T20:45:43.394Z,1534538743.394 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.394Z,1534538743.394 [controlThread](INFO): Join timeout helper Thread ID is 7232
2018-08-17T20:45:43.413Z,1534538743.413 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-17T20:45:43.414Z,1534538743.414 [controlThread](DEBUG): Uninitializing ControlThread
2018-08-17T20:45:43.414Z,1534538743.414 [NAL9602](INFO): Powering down
2018-08-17T20:45:43.416Z,1534538743.416 [PNI_TCM](INFO): Powering down
2018-08-17T20:45:43.506Z,1534538743.506 [Aanderaa_O2](INFO): Powering down
2018-08-17T20:45:43.507Z,1534538743.507 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-17T20:45:43.508Z,1534538743.508 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-08-17T20:45:43.509Z,1534538743.509 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-08-17T20:45:43.510Z,1534538743.510 [MissionManager](INFO): Uninitializing Mission Default
2018-08-17T20:45:43.510Z,1534538743.510 [Default] Stopped
2018-08-17T20:45:43.510Z,1534538743.510 [Default](DEBUG): Aggregate::uninitialize Default
2018-08-17T20:45:43.510Z,1534538743.510 [Default:B.GoToSurface] Stopped
2018-08-17T20:45:43.510Z,1534538743.510 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-17T20:45:43.510Z,1534538743.510 [Default:CheckIn] Stopped
2018-08-17T20:45:43.511Z,1534538743.511 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-17T20:45:43.511Z,1534538743.511 [Default:CheckIn:Read_GPS] Stopped
2018-08-17T20:45:43.515Z,1534538743.515 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-08-17T20:45:43.515Z,1534538743.515 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-08-17T20:45:43.515Z,1534538743.515 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-08-17T20:45:43.516Z,1534538743.516 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-08-17T20:45:43.516Z,1534538743.516 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-08-17T20:45:43.516Z,1534538743.516 [BuoyancyServo](INFO): Powering down
2018-08-17T20:45:43.529Z,1534538743.529 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-08-17T20:45:43.529Z,1534538743.529 [ElevatorServo](INFO): Powering down
2018-08-17T20:45:43.530Z,1534538743.530 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-08-17T20:45:43.530Z,1534538743.530 [MassServo](INFO): Powering down
2018-08-17T20:45:43.531Z,1534538743.531 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-08-17T20:45:43.531Z,1534538743.532 [RudderServo](INFO): Powering down
2018-08-17T20:45:43.533Z,1534538743.533 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-08-17T20:45:43.533Z,1534538743.533 [ThrusterServo](INFO): Powering down
2018-08-17T20:45:43.534Z,1534538743.534 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-08-17T20:45:43.534Z,1534538743.534 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-08-17T20:45:43.535Z,1534538743.535 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-08-17T20:45:43.536Z,1534538743.536 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.667Z,1534538743.667 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.674Z,1534538743.674 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.720Z,1534538743.720 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.722Z,1534538743.722 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.756Z,1534538743.756 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-17T20:45:43.817Z,1534538743.817 [logger ThreadHandler](INFO): Thread cancelled.