2019-01-08T20:52:12.193Z,1546980732.193 [Supervisor](DEBUG): Initializing supervisor.
2019-01-08T20:52:12.196Z,1546980732.196 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-01-08T20:52:12.196Z,1546980732.196 [SyncHandler](INFO): Protected caller Thread ID is 752
2019-01-08T20:52:12.197Z,1546980732.197 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-01-08T20:52:12.198Z,1546980732.198 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-01-08T20:52:12.198Z,1546980732.198 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 753
2019-01-08T20:52:12.202Z,1546980732.202 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-01-08T20:52:12.214Z,1546980732.214 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-01-08T20:52:12.215Z,1546980732.215 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-01-08T20:52:12.215Z,1546980732.215 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 754
2019-01-08T20:52:12.216Z,1546980732.216 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-01-08T20:52:12.217Z,1546980732.217 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-01-08T20:52:12.217Z,1546980732.217 [logger ThreadHandler](INFO): Protected caller Thread ID is 755
2019-01-08T20:52:12.219Z,1546980732.219 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-01-08T20:52:12.219Z,1546980732.219 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-01-08T20:52:12.221Z,1546980732.221 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-01-08T20:52:12.319Z,1546980732.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-01-08T20:52:12.320Z,1546980732.320 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-01-08T20:52:12.420Z,1546980732.420 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-01-08T20:52:12.420Z,1546980732.420 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-01-08T20:52:12.613Z,1546980732.613 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-01-08T20:52:12.613Z,1546980732.613 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-01-08T20:52:12.969Z,1546980732.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-01-08T20:52:12.969Z,1546980732.969 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-01-08T20:52:13.289Z,1546980733.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-01-08T20:52:13.290Z,1546980733.290 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-01-08T20:52:13.738Z,1546980733.738 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-01-08T20:52:13.739Z,1546980733.739 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-01-08T20:52:14.283Z,1546980734.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-01-08T20:52:14.284Z,1546980734.284 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-01-08T20:52:14.730Z,1546980734.730 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-01-08T20:52:14.730Z,1546980734.730 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-01-08T20:52:14.811Z,1546980734.811 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-01-08T20:52:15.115Z,1546980735.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-01-08T20:52:15.115Z,1546980735.115 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-01-08T20:52:15.262Z,1546980735.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-01-08T20:52:15.263Z,1546980735.263 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-01-08T20:52:15.477Z,1546980735.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-01-08T20:52:15.478Z,1546980735.478 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-01-08T20:52:15.680Z,1546980735.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-01-08T20:52:15.680Z,1546980735.680 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-01-08T20:52:15.779Z,1546980735.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-01-08T20:52:15.779Z,1546980735.779 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-01-08T20:52:15.923Z,1546980735.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-01-08T20:52:15.925Z,1546980735.925 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-01-08T20:52:15.926Z,1546980735.926 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-01-08T20:52:16.157Z,1546980736.157 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-01-08T20:52:16.157Z,1546980736.157 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-01-08T20:52:16.262Z,1546980736.262 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-01-08T20:52:16.411Z,1546980736.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-01-08T20:52:16.505Z,1546980736.505 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-01-08T20:52:16.591Z,1546980736.591 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-01-08T20:52:16.748Z,1546980736.748 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-01-08T20:52:16.957Z,1546980736.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-01-08T20:52:17.230Z,1546980737.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-01-08T20:52:17.361Z,1546980737.361 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-01-08T20:52:17.460Z,1546980737.460 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-01-08T20:52:17.544Z,1546980737.544 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-01-08T20:52:17.544Z,1546980737.544 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-01-08T20:52:17.550Z,1546980737.550 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-01-08T20:52:17.647Z,1546980737.647 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-01-08T20:52:17.647Z,1546980737.647 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-01-08T20:52:17.661Z,1546980737.661 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-01-08T20:52:17.661Z,1546980737.661 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-01-08T20:52:17.703Z,1546980737.703 [DepthRateCalculator] Loaded
2019-01-08T20:52:17.704Z,1546980737.704 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-01-08T20:52:17.709Z,1546980737.709 [PitchRateCalculator] Loaded
2019-01-08T20:52:17.710Z,1546980737.710 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-01-08T20:52:17.725Z,1546980737.725 [SpeedCalculator] Loaded
2019-01-08T20:52:17.725Z,1546980737.725 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-01-08T20:52:17.745Z,1546980737.745 [TempGradientCalculator] Loaded
2019-01-08T20:52:17.745Z,1546980737.745 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-01-08T20:52:17.751Z,1546980737.751 [YawRateCalculator] Loaded
2019-01-08T20:52:17.751Z,1546980737.751 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-01-08T20:52:17.789Z,1546980737.789 [ElevatorOffsetCalculator] Loaded
2019-01-08T20:52:17.789Z,1546980737.789 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-01-08T20:52:17.789Z,1546980737.789 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-01-08T20:52:17.790Z,1546980737.790 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-01-08T20:52:17.816Z,1546980737.816 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-01-08T20:52:17.817Z,1546980737.817 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-01-08T20:52:18.081Z,1546980738.081 [AcousticModem_Benthos_ATM900] Loaded
2019-01-08T20:52:18.081Z,1546980738.081 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-01-08T20:52:18.148Z,1546980738.148 [DataOverHttps] Loaded
2019-01-08T20:52:18.148Z,1546980738.148 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-01-08T20:52:18.161Z,1546980738.161 [Depth_Keller] Loaded
2019-01-08T20:52:18.161Z,1546980738.161 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-01-08T20:52:18.255Z,1546980738.255 [NAL9602] Loaded
2019-01-08T20:52:18.256Z,1546980738.256 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-01-08T20:52:18.271Z,1546980738.271 [Onboard] Loaded
2019-01-08T20:52:18.271Z,1546980738.271 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-01-08T20:52:18.281Z,1546980738.281 [Radio_Surface] Loaded
2019-01-08T20:52:18.281Z,1546980738.281 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-01-08T20:52:18.282Z,1546980738.282 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407CE4E0
2019-01-08T20:52:18.282Z,1546980738.282 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 841
2019-01-08T20:52:18.328Z,1546980738.328 [PNI_TCM] Loaded
2019-01-08T20:52:18.328Z,1546980738.328 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-01-08T20:52:18.385Z,1546980738.385 [Rowe_600LCM] Loaded
2019-01-08T20:52:18.385Z,1546980738.385 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-01-08T20:52:18.386Z,1546980738.386 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407FE4E0
2019-01-08T20:52:18.387Z,1546980738.387 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 842
2019-01-08T20:52:20.079Z,1546980740.079 [BPC1] Loaded
2019-01-08T20:52:20.080Z,1546980740.080 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-01-08T20:52:20.080Z,1546980740.080 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-01-08T20:52:20.080Z,1546980740.080 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-01-08T20:52:20.210Z,1546980740.210 [SBIT](DEBUG): Construct Startup Built In Test.
2019-01-08T20:52:20.232Z,1546980740.232 [SBIT] Loaded
2019-01-08T20:52:20.232Z,1546980740.232 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-01-08T20:52:20.233Z,1546980740.233 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-01-08T20:52:20.245Z,1546980740.245 [IBIT] Loaded
2019-01-08T20:52:20.245Z,1546980740.245 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-01-08T20:52:20.248Z,1546980740.248 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-01-08T20:52:20.383Z,1546980740.383 [CBIT] Loaded
2019-01-08T20:52:20.383Z,1546980740.383 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-01-08T20:52:20.383Z,1546980740.383 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-01-08T20:52:20.384Z,1546980740.384 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-01-08T20:52:20.557Z,1546980740.557 [ESPComponent] Loaded
2019-01-08T20:52:20.557Z,1546980740.557 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-01-08T20:52:20.571Z,1546980740.571 [PAR_Licor] Loaded
2019-01-08T20:52:20.572Z,1546980740.572 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-01-08T20:52:20.619Z,1546980740.619 [WetLabsBB2FL] Loaded
2019-01-08T20:52:20.619Z,1546980740.619 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-01-08T20:52:20.620Z,1546980740.620 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408DE4E0
2019-01-08T20:52:20.621Z,1546980740.621 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 843
2019-01-08T20:52:20.621Z,1546980740.621 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-01-08T20:52:20.622Z,1546980740.622 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-01-08T20:52:20.850Z,1546980740.850 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-01-08T20:52:20.851Z,1546980740.851 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-01-08T20:52:20.918Z,1546980740.918 [VerticalControl](DEBUG): Construct VerticalControl.
2019-01-08T20:52:21.009Z,1546980741.009 [VerticalControl] Loaded
2019-01-08T20:52:21.009Z,1546980741.009 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-01-08T20:52:21.010Z,1546980741.010 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-01-08T20:52:21.068Z,1546980741.068 [HorizontalControl] Loaded
2019-01-08T20:52:21.068Z,1546980741.068 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-01-08T20:52:21.069Z,1546980741.069 [SpeedControl](DEBUG): Construct SpeedControl.
2019-01-08T20:52:21.074Z,1546980741.074 [SpeedControl] Loaded
2019-01-08T20:52:21.074Z,1546980741.074 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-01-08T20:52:21.075Z,1546980741.075 [LoopControl](DEBUG): Construct LoopControl.
2019-01-08T20:52:21.075Z,1546980741.075 [LoopControl] Loaded
2019-01-08T20:52:21.075Z,1546980741.075 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-01-08T20:52:21.076Z,1546980741.076 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-01-08T20:52:21.076Z,1546980741.076 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-01-08T20:52:21.142Z,1546980741.142 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-01-08T20:52:21.142Z,1546980741.142 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-01-08T20:52:21.238Z,1546980741.238 [BuoyancyServo] Loaded
2019-01-08T20:52:21.238Z,1546980741.238 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-01-08T20:52:21.249Z,1546980741.249 [ElevatorServo] Loaded
2019-01-08T20:52:21.249Z,1546980741.249 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-01-08T20:52:21.260Z,1546980741.260 [MassServo] Loaded
2019-01-08T20:52:21.260Z,1546980741.260 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-01-08T20:52:21.271Z,1546980741.271 [RudderServo] Loaded
2019-01-08T20:52:21.271Z,1546980741.271 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-01-08T20:52:21.282Z,1546980741.282 [ThrusterServo] Loaded
2019-01-08T20:52:21.282Z,1546980741.282 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-01-08T20:52:21.282Z,1546980741.282 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-01-08T20:52:21.283Z,1546980741.283 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-01-08T20:52:21.377Z,1546980741.377 [DeadReckonUsingSpeedCalculator] Loaded
2019-01-08T20:52:21.377Z,1546980741.377 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-01-08T20:52:21.393Z,1546980741.393 [NavChart] Loaded
2019-01-08T20:52:21.393Z,1546980741.393 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-01-08T20:52:21.397Z,1546980741.397 [UniversalFixResidualReporter] Loaded
2019-01-08T20:52:21.397Z,1546980741.397 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-01-08T20:52:21.397Z,1546980741.397 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-01-08T20:52:21.401Z,1546980741.401 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-01-08T20:52:21.402Z,1546980741.402 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-01-08T20:52:21.409Z,1546980741.409 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-01-08T20:52:21.410Z,1546980741.410 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A384E0
2019-01-08T20:52:21.410Z,1546980741.410 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 844
2019-01-08T20:52:21.415Z,1546980741.415 [Supervisor](INFO): Main Thread ID is 750
2019-01-08T20:52:21.415Z,1546980741.415 [Supervisor](DEBUG): Running supervisor.
2019-01-08T20:52:21.416Z,1546980741.416 [CommandLine ThreadHandler](INFO): Handler Thread ID is 845
2019-01-08T20:52:21.418Z,1546980741.418 [controlThread ThreadHandler](INFO): Handler Thread ID is 846
2019-01-08T20:52:21.419Z,1546980741.419 [controlThread](DEBUG): Initializing ControlThread
2019-01-08T20:52:21.420Z,1546980741.420 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-01-08T20:52:21.420Z,1546980741.420 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-01-08T20:52:21.420Z,1546980741.420 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-01-08T20:52:21.420Z,1546980741.420 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-01-08T20:52:21.421Z,1546980741.421 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-01-08T20:52:21.421Z,1546980741.421 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-01-08T20:52:21.427Z,1546980741.427 [SBIT](INFO): Initialize SBIT Component.
2019-01-08T20:52:21.428Z,1546980741.428 [SBIT](IMPORTANT): git: 2018-12-19-7-ge6e97dd
2019-01-08T20:52:21.428Z,1546980741.428 [SBIT](INFO): git hash: e6e97ddedb109e04c53e263f45ff20387b96d5aa
2019-01-08T20:52:21.428Z,1546980741.428 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-01-08T20:52:21.429Z,1546980741.429 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-01-08T20:52:21.430Z,1546980741.430 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-01-08T20:52:21.431Z,1546980741.431 [IBIT](INFO): Initialize IBIT Component.
2019-01-08T20:52:21.432Z,1546980741.432 [CBIT](DEBUG): Initialize CBIT Component.
2019-01-08T20:52:21.433Z,1546980741.433 [logger ThreadHandler](INFO): Handler Thread ID is 847
2019-01-08T20:52:21.446Z,1546980741.446 [CBIT](DEBUG): Initialized mux pins.
2019-01-08T20:52:21.446Z,1546980741.446 [CBIT](DEBUG): Initializing the watchdog timer.
2019-01-08T20:52:21.450Z,1546980741.450 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 848
2019-01-08T20:52:21.456Z,1546980741.456 [Radio_Surface](INFO): Powering up
2019-01-08T20:52:21.466Z,1546980741.466 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 849
2019-01-08T20:52:21.467Z,1546980741.467 [Rowe_600LCM](INFO): Initializing
2019-01-08T20:52:21.474Z,1546980741.474 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-01-08T20:52:21.474Z,1546980741.474 [CBIT](DEBUG): Initializing heartbeat.
2019-01-08T20:52:21.477Z,1546980741.477 [Rowe_600LCM](INFO): Powering up
2019-01-08T20:52:21.483Z,1546980741.483 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 850
2019-01-08T20:52:21.484Z,1546980741.484 [WetLabsBB2FL](INFO): Powering down
2019-01-08T20:52:21.511Z,1546980741.511 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 851
2019-01-08T20:52:21.514Z,1546980741.514 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-01-08T20:52:21.514Z,1546980741.514 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-01-08T20:52:21.514Z,1546980741.514 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-01-08T20:52:21.515Z,1546980741.515 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-01-08T20:52:21.515Z,1546980741.515 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-01-08T20:52:21.515Z,1546980741.515 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-01-08T20:52:21.515Z,1546980741.515 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-01-08T20:52:21.515Z,1546980741.515 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-01-08T20:52:21.516Z,1546980741.516 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-01-08T20:52:21.516Z,1546980741.516 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-01-08T20:52:21.516Z,1546980741.516 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-01-08T20:52:21.516Z,1546980741.516 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-01-08T20:52:21.516Z,1546980741.516 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-01-08T20:52:21.516Z,1546980741.516 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-01-08T20:52:21.517Z,1546980741.517 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-01-08T20:52:21.517Z,1546980741.517 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-01-08T20:52:21.546Z,1546980741.546 [CBIT](DEBUG): Deactivating GF circuits.
2019-01-08T20:52:21.546Z,1546980741.546 [CBIT](DEBUG): Deactivating emergency mode.
2019-01-08T20:52:21.586Z,1546980741.586 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-01-08T20:52:21.588Z,1546980741.588 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-01-08T20:52:21.589Z,1546980741.589 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-01-08T20:52:21.589Z,1546980741.589 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-01-08T20:52:21.591Z,1546980741.591 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T20:52:21.592Z,1546980741.592 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T20:52:21.592Z,1546980741.592 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T20:52:21.592Z,1546980741.592 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-01-08T20:52:21.593Z,1546980741.593 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-01-08T20:52:21.594Z,1546980741.594 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-01-08T20:52:21.618Z,1546980741.618 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-08T20:52:21.640Z,1546980741.640 [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>


2019-01-08T20:52:21.641Z,1546980741.641 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-01-08T20:52:21.735Z,1546980741.735 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-01-08T20:52:21.736Z,1546980741.736 [Default:A.Wait](DEBUG): Construct Wait.
2019-01-08T20:52:21.738Z,1546980741.738 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-08T20:52:21.784Z,1546980741.784 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-01-08T20:52:21.803Z,1546980741.803 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-01-08T20:52:21.808Z,1546980741.808 [Default:E.Execute](DEBUG): Construct Execute.
2019-01-08T20:52:21.832Z,1546980741.832 [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 on</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>


2019-01-08T20:52:21.836Z,1546980741.836 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-01-08T20:52:21.857Z,1546980741.857 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-01-08T20:52:21.857Z,1546980741.857 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-01-08T20:52:21.885Z,1546980741.885 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-01-08T20:52:22.176Z,1546980742.176 [ESPComponent](INFO): powering down ESP
2019-01-08T20:52:22.666Z,1546980742.666 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-01-08T20:52:22.674Z,1546980742.674 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-01-08T20:52:22.700Z,1546980742.700 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-01-08T20:52:22.706Z,1546980742.706 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-01-08T20:52:22.712Z,1546980742.712 [MassServo](DEBUG): Initializing EZServoServo.
2019-01-08T20:52:22.718Z,1546980742.718 [MassServo](DEBUG): Initializing MassServo.
2019-01-08T20:52:22.724Z,1546980742.724 [RudderServo](DEBUG): Initializing EZServoServo.
2019-01-08T20:52:22.730Z,1546980742.730 [RudderServo](DEBUG): Initializing RudderServo.
2019-01-08T20:52:22.736Z,1546980742.736 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-01-08T20:52:22.742Z,1546980742.742 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-01-08T20:52:25.808Z,1546980745.808 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-01-08T20:52:25.989Z,1546980745.989 [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 &
2019-01-08T20:52:40.618Z,1546980760.618 [CBIT](CRITICAL): Environmental Failure. Press:14.720627 PSI. Humidity:41%. Temp:25 C. ABORTING MISSION
2019-01-08T20:52:40.619Z,1546980760.619 [Supervisor](INFO): Stop Mission called by CBIT::monitorEnvironmentals
2019-01-08T20:52:40.638Z,1546980760.638 [AcousticModem_Benthos_ATM900](DEBUG): 
2019-01-08T20:52:40.640Z,1546980760.640 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2019-01-08T20:52:40.640Z,1546980760.640 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-01-08T20:52:40.641Z,1546980760.641 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2019-01-08T20:52:40.654Z,1546980760.654 [AcousticModem_Benthos_ATM900](DEBUG): Jan  8 2019 20:51:39 
2019-01-08T20:52:40.655Z,1546980760.655 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2019-01-08T20:52:40.939Z,1546980760.939 [CommandLine](FAULT): Scheduling is paused
2019-01-08T20:52:40.939Z,1546980760.939 [CBIT](INFO): Critical error at 20190108T205240
2019-01-08T20:52:41.427Z,1546980761.427 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-01-08T20:52:41.433Z,1546980761.433 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004875
2019-01-08T20:52:41.831Z,1546980761.831 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2019-01-08T20:52:41.833Z,1546980761.833 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2019-01-08T20:52:41.833Z,1546980761.833 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2019-01-08T20:52:42.227Z,1546980762.227 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-01-08T20:52:42.227Z,1546980762.227 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1
2019-01-08T20:52:42.227Z,1546980762.227 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-01-08T20:52:42.493Z,1546980762.493 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-01-08T20:52:42.627Z,1546980762.627 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-01-08T20:52:43.533Z,1546980763.533 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-01-08T20:52:43.533Z,1546980763.533 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1
2019-01-08T20:52:45.827Z,1546980765.827 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-01-08T20:52:45.827Z,1546980765.827 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-01-08T20:52:45.979Z,1546980765.979 [SBIT](IMPORTANT): Beginning Startup BIT
2019-01-08T20:52:45.993Z,1546980765.993 [CBIT](IMPORTANT): Beginning ground fault scan
2019-01-08T20:52:48.496Z,1546980768.496 [NAL9602](INFO): Powering up NAL9602
2019-01-08T20:52:51.634Z,1546980771.634 [CBIT](INFO): A/D timeout, 4 tries over 150 ms

2019-01-08T20:52:53.291Z,1546980773.291 [AcousticModem_Benthos_ATM900](DEBUG): 
2019-01-08T20:52:54.495Z,1546980774.495 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2019-01-08T20:52:54.496Z,1546980774.496 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-01-08T20:52:54.496Z,1546980774.496 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2019-01-08T20:52:54.893Z,1546980774.893 [AcousticModem_Benthos_ATM900](DEBUG): Jan  8 2019 20:52:03 
2019-01-08T20:52:55.292Z,1546980775.292 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2019-01-08T20:52:56.095Z,1546980776.095 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-01-08T20:52:56.491Z,1546980776.491 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2019-01-08T20:52:56.492Z,1546980776.492 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2019-01-08T20:52:56.492Z,1546980776.492 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2019-01-08T20:52:56.893Z,1546980776.893 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2019-01-08T20:52:57.100Z,1546980777.100 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009332
CHAN A1 (24V): -0.013150
CHAN A2 (12V): -0.005338
CHAN A3 (5V): nan
CHAN B0 (3.3V): 0.010236
CHAN B1 (3.15aV): -0.000735
CHAN B2 (3.15bV): -0.000919
CHAN B3 (GND): 0.000179
OPEN: 0.004129
Full Scale Calc: 4.765 mA, -1.589 mA
2019-01-08T20:52:57.291Z,1546980777.291 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2019-01-08T20:52:57.292Z,1546980777.292 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2019-01-08T20:52:57.692Z,1546980777.692 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2019-01-08T20:52:59.295Z,1546980779.295 [NAL9602](INFO): NAL9602 initialized
2019-01-08T20:53:33.306Z,1546980813.306 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-01-08T20:53:33.306Z,1546980813.306 [BPC1] Data Fault, FailCount= 1
2019-01-08T20:53:33.306Z,1546980813.306 [BPC1](ERROR): Data Fault
2019-01-08T20:53:33.459Z,1546980813.459 [CBIT](ERROR): Data Fault in component: BPC1
2019-01-08T20:53:42.959Z,1546980822.959 [SBIT](IMPORTANT): SBIT PASSED
2019-01-08T20:53:43.087Z,1546980823.087 [CommandLine](IMPORTANT): got command configSet list
2019-01-08T20:53:43.087Z,1546980823.087 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-01-08T20:53:43.088Z,1546980823.088 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-01-08T20:53:43.089Z,1546980823.089 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2019-01-08T20:53:43.089Z,1546980823.089 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-01-08T20:53:43.089Z,1546980823.089 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-01-08T20:53:43.089Z,1546980823.089 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool;

2019-01-08T20:53:43.309Z,1546980823.309 [MissionManager](IMPORTANT): Started mission Startup
2019-01-08T20:53:43.310Z,1546980823.310 [Startup] Running Loop=1
2019-01-08T20:53:43.310Z,1546980823.310 [Startup](DEBUG): Aggregate::initialize Startup
2019-01-08T20:53:43.310Z,1546980823.310 [Startup:A.GoToSurface] Running Loop=1
2019-01-08T20:53:43.310Z,1546980823.310 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-01-08T20:53:43.311Z,1546980823.311 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-01-08T20:53:43.311Z,1546980823.311 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-01-08T20:53:43.311Z,1546980823.311 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-01-08T20:53:43.312Z,1546980823.312 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-01-08T20:53:43.312Z,1546980823.312 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-01-08T20:53:43.317Z,1546980823.317 [Startup:StartupSatComms] Running Loop=1
2019-01-08T20:53:43.318Z,1546980823.318 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-01-08T20:53:43.330Z,1546980823.330 [Startup:StartupSatComms:A] Running Loop=1
2019-01-08T20:53:43.717Z,1546980823.717 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-01-08T20:54:43.506Z,1546980883.506 [Startup:StartupSatComms:A](INFO): Timed out from 2019-01-08T20:53:43.3Z
2019-01-08T20:54:43.506Z,1546980883.506 [Startup:StartupSatComms:A] Stopped
2019-01-08T20:54:43.506Z,1546980883.506 [Startup:StartupSatComms:B] Running Loop=1
2019-01-08T20:54:43.916Z,1546980883.916 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-01-08T20:54:51.600Z,1546980891.600 [DataOverHttps](INFO): Sending 392 bytes from file Logs/20190108T183055/Courier0000.lzma
2019-01-08T20:54:52.390Z,1546980892.390 [DataOverHttps](INFO): Moved sent file to Logs/20190108T183055/Courier0000.lzma.bak
2019-01-08T20:54:52.390Z,1546980892.390 [DataOverHttps](INFO): SBD MOMSN=9159110
2019-01-08T20:55:07.768Z,1546980907.768 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190108T183055/Courier0004.lzma
2019-01-08T20:55:08.537Z,1546980908.537 [DataOverHttps](INFO): Moved sent file to Logs/20190108T183055/Courier0004.lzma.bak
2019-01-08T20:55:08.537Z,1546980908.537 [DataOverHttps](INFO): SBD MOMSN=9159129
2019-01-08T20:55:18.900Z,1546980918.900 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20190108T205212/Courier0000.lzma
2019-01-08T20:55:19.705Z,1546980919.705 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Courier0000.lzma.bak
2019-01-08T20:55:19.705Z,1546980919.705 [DataOverHttps](INFO): SBD MOMSN=9159131
2019-01-08T20:55:22.923Z,1546980922.923 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000161.783631
2019-01-08T20:55:22.923Z,1546980922.923 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-01-08T20:55:22.923Z,1546980922.923 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T20:55:22.947Z,1546980922.947 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T20:55:23.052Z,1546980923.052 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T20:55:23.052Z,1546980923.052 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-01-08T20:55:26.444Z,1546980926.444 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T20:55:26.444Z,1546980926.444 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T20:55:26.445Z,1546980926.445 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T20:55:31.531Z,1546980931.531 [DataOverHttps](INFO): Sending 753 bytes from file Logs/20190108T183055/Express0001.lzma
2019-01-08T20:55:32.317Z,1546980932.317 [DataOverHttps](INFO): Moved sent file to Logs/20190108T183055/Express0001.lzma.bak
2019-01-08T20:55:32.317Z,1546980932.317 [DataOverHttps](INFO): SBD MOMSN=9159135
2019-01-08T20:55:46.447Z,1546980946.447 [Startup:StartupSatComms:B](INFO): Timed out from 2019-01-08T20:54:43.5Z
2019-01-08T20:55:46.448Z,1546980946.448 [Startup:StartupSatComms:B] Stopped
2019-01-08T20:55:46.448Z,1546980946.448 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-01-08T20:55:46.448Z,1546980946.448 [Startup:StartupSatComms] Stopped
2019-01-08T20:55:46.448Z,1546980946.448 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-01-08T20:55:46.449Z,1546980946.449 [Startup](INFO): Completed Startup
2019-01-08T20:55:46.449Z,1546980946.449 [MissionManager](INFO): Startup is completed.
2019-01-08T20:55:46.449Z,1546980946.449 [MissionManager](INFO): Uninitializing Mission Startup
2019-01-08T20:55:46.449Z,1546980946.449 [Startup] Stopped
2019-01-08T20:55:46.449Z,1546980946.449 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-01-08T20:55:46.449Z,1546980946.449 [Startup:A.GoToSurface] Stopped
2019-01-08T20:55:46.449Z,1546980946.449 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-01-08T20:55:46.522Z,1546980946.522 [DataOverHttps](INFO): Sending 290 bytes from file Logs/20190108T183055/Express0005.lzma
2019-01-08T20:55:46.583Z,1546980946.583 [MissionManager](IMPORTANT): Started mission Default
2019-01-08T20:55:46.583Z,1546980946.583 [Default] Running Loop=1
2019-01-08T20:55:46.587Z,1546980946.587 [Default](DEBUG): Aggregate::initialize Default
2019-01-08T20:55:46.587Z,1546980946.587 [Default:B.GoToSurface] Running Loop=1
2019-01-08T20:55:46.587Z,1546980946.587 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-01-08T20:55:46.588Z,1546980946.588 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-01-08T20:55:46.588Z,1546980946.588 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-01-08T20:55:46.588Z,1546980946.588 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-01-08T20:55:46.589Z,1546980946.589 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-01-08T20:55:46.589Z,1546980946.589 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-01-08T20:55:46.589Z,1546980946.589 [Default:A.Wait] Running Loop=1
2019-01-08T20:55:46.589Z,1546980946.589 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-01-08T20:55:47.287Z,1546980947.287 [DataOverHttps](INFO): Moved sent file to Logs/20190108T183055/Express0005.lzma.bak
2019-01-08T20:55:47.288Z,1546980947.288 [DataOverHttps](INFO): SBD MOMSN=9159155
2019-01-08T20:55:59.950Z,1546980959.950 [Default:A.Wait](INFO): Done Waiting.
2019-01-08T20:55:59.950Z,1546980959.950 [Default:A.Wait] Stopped
2019-01-08T20:55:59.950Z,1546980959.950 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-01-08T20:56:00.354Z,1546980960.354 [Default:CheckIn] Running Loop=1
2019-01-08T20:56:00.354Z,1546980960.354 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-01-08T20:56:00.354Z,1546980960.354 [Default:CheckIn:Read_GPS] Running Loop=1
2019-01-08T20:56:00.742Z,1546980960.742 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-01-08T20:58:02.751Z,1546981082.751 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-01-08T20:58:26.820Z,1546981106.820 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000345.696665
2019-01-08T20:58:26.820Z,1546981106.820 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2019-01-08T20:58:26.820Z,1546981106.820 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T20:58:26.832Z,1546981106.832 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T20:58:27.221Z,1546981107.221 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T20:58:27.222Z,1546981107.222 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2019-01-08T20:58:27.618Z,1546981107.618 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T20:58:27.619Z,1546981107.619 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T20:58:27.619Z,1546981107.619 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:01:00.377Z,1546981260.377 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-01-08T20:56:00.4Z
2019-01-08T21:01:00.378Z,1546981260.378 [Default:CheckIn:Read_GPS] Stopped
2019-01-08T21:01:00.378Z,1546981260.378 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-01-08T21:01:00.804Z,1546981260.804 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-01-08T21:01:05.997Z,1546981265.997 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190108T205212/Courier0004.lzma
2019-01-08T21:01:06.797Z,1546981266.797 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Courier0004.lzma.bak
2019-01-08T21:01:06.797Z,1546981266.797 [DataOverHttps](INFO): SBD MOMSN=9159191
2019-01-08T21:01:18.800Z,1546981278.800 [DataOverHttps](INFO): Sending 807 bytes from file Logs/20190108T205212/Express0001.lzma
2019-01-08T21:01:19.565Z,1546981279.565 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Express0001.lzma.bak
2019-01-08T21:01:19.565Z,1546981279.565 [DataOverHttps](INFO): SBD MOMSN=9159193
2019-01-08T21:01:27.623Z,1546981287.623 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000526.500037
2019-01-08T21:01:27.623Z,1546981287.623 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2019-01-08T21:01:27.624Z,1546981287.624 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:01:27.656Z,1546981287.656 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:01:28.050Z,1546981288.050 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:01:28.050Z,1546981288.050 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2019-01-08T21:01:28.427Z,1546981288.427 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:01:28.428Z,1546981288.428 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:01:28.428Z,1546981288.428 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:01:32.256Z,1546981292.256 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20190108T205212/Express0005.lzma
2019-01-08T21:01:33.045Z,1546981293.045 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Express0005.lzma.bak
2019-01-08T21:01:33.045Z,1546981293.045 [DataOverHttps](INFO): SBD MOMSN=9159213
2019-01-08T21:01:36.333Z,1546981296.333 [Default:CheckIn:Read_Iridium] Stopped
2019-01-08T21:01:36.333Z,1546981296.333 [Default:CheckIn:C.Wait] Running Loop=1
2019-01-08T21:01:36.333Z,1546981296.333 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-01-08T21:03:00.127Z,1546981380.127 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-01-08T21:03:00.127Z,1546981380.127 [NAL9602] Data Fault, FailCount= 1
2019-01-08T21:03:00.128Z,1546981380.128 [NAL9602](ERROR): Data Fault
2019-01-08T21:03:00.216Z,1546981380.216 [CBIT](ERROR): Data Fault in component: NAL9602
2019-01-08T21:03:00.527Z,1546981380.527 [NAL9602](INFO): Powering down
2019-01-08T21:03:01.393Z,1546981381.393 [CBIT](INFO): Clearing failed state for component NAL9602
2019-01-08T21:03:01.393Z,1546981381.393 [NAL9602] No Fault, FailCount= 1
2019-01-08T21:03:30.535Z,1546981410.535 [NAL9602](INFO): Powering up NAL9602
2019-01-08T21:03:34.204Z,1546981414.204 [CBIT](INFO): Clearing failed state for component BPC1
2019-01-08T21:03:34.204Z,1546981414.204 [BPC1] No Fault, FailCount= 1
2019-01-08T21:03:41.563Z,1546981421.563 [NAL9602](INFO): NAL9602 initialized
2019-01-08T21:04:28.794Z,1546981468.794 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000707.671149
2019-01-08T21:04:28.794Z,1546981468.794 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2019-01-08T21:04:28.795Z,1546981468.795 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:04:28.839Z,1546981468.839 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:04:29.240Z,1546981469.240 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:04:29.240Z,1546981469.240 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2019-01-08T21:04:29.594Z,1546981469.594 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:04:29.594Z,1546981469.594 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:04:29.595Z,1546981469.595 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:04:40.763Z,1546981480.763 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-01-08T21:04:40.763Z,1546981480.763 [BPC1] Data Fault, FailCount= 2
2019-01-08T21:04:40.763Z,1546981480.763 [BPC1](ERROR): Data Fault
2019-01-08T21:04:40.834Z,1546981480.834 [CBIT](ERROR): Data Fault in component: BPC1
2019-01-08T21:06:36.542Z,1546981596.542 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-01-08T21:06:36.542Z,1546981596.542 [Default:CheckIn:C.Wait] Stopped
2019-01-08T21:06:36.542Z,1546981596.542 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-01-08T21:06:36.542Z,1546981596.542 [Default:CheckIn:D] Running Loop=1
2019-01-08T21:06:36.940Z,1546981596.940 [Default:CheckIn:D] Stopped
2019-01-08T21:06:36.940Z,1546981596.940 [Default:CheckIn:E] Running Loop=1
2019-01-08T21:06:37.342Z,1546981597.342 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.838963 min 
2019-01-08T21:06:37.344Z,1546981597.344 [Default:CheckIn:E] Stopped
2019-01-08T21:06:37.344Z,1546981597.344 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-01-08T21:06:37.344Z,1546981597.344 [Default:CheckIn] Stopped
2019-01-08T21:06:37.344Z,1546981597.344 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-01-08T21:06:37.344Z,1546981597.344 [Default:CheckIn](INFO): Running loop #2
2019-01-08T21:06:37.345Z,1546981597.345 [Default:CheckIn] Running Loop=2
2019-01-08T21:06:37.345Z,1546981597.345 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-01-08T21:06:37.345Z,1546981597.345 [Default:CheckIn:Read_GPS] Running Loop=1
2019-01-08T21:07:29.658Z,1546981649.658 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000888.534705
2019-01-08T21:07:29.666Z,1546981649.666 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2019-01-08T21:07:29.666Z,1546981649.666 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:07:29.723Z,1546981649.723 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:07:30.116Z,1546981650.116 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:07:30.116Z,1546981650.116 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2019-01-08T21:07:30.464Z,1546981650.464 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:07:30.464Z,1546981650.464 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:07:30.465Z,1546981650.465 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:10:30.533Z,1546981830.533 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001069.409774
2019-01-08T21:10:30.533Z,1546981830.533 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2019-01-08T21:10:30.534Z,1546981830.534 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:10:30.565Z,1546981830.565 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:10:30.933Z,1546981830.933 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:10:30.933Z,1546981830.933 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2019-01-08T21:10:31.321Z,1546981831.321 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:10:31.322Z,1546981831.322 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:10:31.322Z,1546981831.322 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:11:37.531Z,1546981897.531 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-01-08T21:06:37.3Z
2019-01-08T21:11:37.531Z,1546981897.531 [Default:CheckIn:Read_GPS] Stopped
2019-01-08T21:11:37.531Z,1546981897.531 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-01-08T21:11:43.353Z,1546981903.353 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190108T205212/Courier0007.lzma
2019-01-08T21:11:44.153Z,1546981904.153 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Courier0007.lzma.bak
2019-01-08T21:11:44.153Z,1546981904.153 [DataOverHttps](INFO): SBD MOMSN=9159217
2019-01-08T21:11:57.896Z,1546981917.896 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20190108T205212/Express0008.lzma
2019-01-08T21:11:58.700Z,1546981918.700 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Express0008.lzma.bak
2019-01-08T21:11:58.700Z,1546981918.700 [DataOverHttps](INFO): SBD MOMSN=9159219
2019-01-08T21:12:01.980Z,1546981921.980 [Default:CheckIn:Read_Iridium] Stopped
2019-01-08T21:12:01.980Z,1546981921.980 [Default:CheckIn:C.Wait] Running Loop=1
2019-01-08T21:12:01.980Z,1546981921.980 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-01-08T21:13:31.653Z,1546982011.653 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001250.529573
2019-01-08T21:13:31.653Z,1546982011.653 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2019-01-08T21:13:31.653Z,1546982011.653 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:13:31.694Z,1546982011.694 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:13:32.043Z,1546982012.043 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:13:32.043Z,1546982012.043 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2019-01-08T21:13:32.451Z,1546982012.451 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:13:32.451Z,1546982012.451 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:13:32.452Z,1546982012.452 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:13:42.800Z,1546982022.800 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-01-08T21:13:42.800Z,1546982022.800 [NAL9602] Data Fault, FailCount= 2
2019-01-08T21:13:42.800Z,1546982022.800 [NAL9602](ERROR): Data Fault
2019-01-08T21:13:42.958Z,1546982022.958 [CBIT](ERROR): Data Fault in component: NAL9602
2019-01-08T21:13:43.195Z,1546982023.195 [NAL9602](INFO): Powering down
2019-01-08T21:13:44.056Z,1546982024.056 [CBIT](INFO): Clearing failed state for component NAL9602
2019-01-08T21:13:44.057Z,1546982024.057 [NAL9602] No Fault, FailCount= 2
2019-01-08T21:14:13.439Z,1546982053.439 [NAL9602](INFO): Powering up NAL9602
2019-01-08T21:14:24.636Z,1546982064.636 [NAL9602](INFO): NAL9602 initialized
2019-01-08T21:14:41.911Z,1546982081.911 [CBIT](INFO): Clearing failed state for component BPC1
2019-01-08T21:14:41.911Z,1546982081.911 [BPC1] No Fault, FailCount= 2
2019-01-08T21:16:32.808Z,1546982192.808 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001431.684603
2019-01-08T21:16:32.808Z,1546982192.808 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2019-01-08T21:16:32.808Z,1546982192.808 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:16:32.820Z,1546982192.820 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:16:33.294Z,1546982193.294 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:16:33.294Z,1546982193.294 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2019-01-08T21:16:33.595Z,1546982193.595 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:16:33.596Z,1546982193.596 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:16:33.596Z,1546982193.596 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:17:02.421Z,1546982222.421 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-01-08T21:17:02.421Z,1546982222.421 [Default:CheckIn:C.Wait] Stopped
2019-01-08T21:17:02.421Z,1546982222.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-01-08T21:17:02.421Z,1546982222.421 [Default:CheckIn:D] Running Loop=1
2019-01-08T21:17:02.808Z,1546982222.808 [Default:CheckIn:D] Stopped
2019-01-08T21:17:02.808Z,1546982222.808 [Default:CheckIn:E] Running Loop=1
2019-01-08T21:17:03.250Z,1546982223.250 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.270408 min 
2019-01-08T21:17:03.251Z,1546982223.251 [Default:CheckIn:E] Stopped
2019-01-08T21:17:03.251Z,1546982223.251 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-01-08T21:17:03.251Z,1546982223.251 [Default:CheckIn] Stopped
2019-01-08T21:17:03.251Z,1546982223.251 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-01-08T21:17:03.251Z,1546982223.251 [Default:CheckIn](INFO): Running loop #3
2019-01-08T21:17:03.251Z,1546982223.251 [Default:CheckIn] Running Loop=3
2019-01-08T21:17:03.251Z,1546982223.251 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-01-08T21:17:03.252Z,1546982223.252 [Default:CheckIn:Read_GPS] Running Loop=1
2019-01-08T21:19:33.745Z,1546982373.745 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001612.621706
2019-01-08T21:19:33.745Z,1546982373.745 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2019-01-08T21:19:33.745Z,1546982373.745 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:19:33.766Z,1546982373.766 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:19:34.206Z,1546982374.206 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:19:34.206Z,1546982374.206 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2019-01-08T21:19:34.528Z,1546982374.528 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:19:34.528Z,1546982374.528 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:19:34.529Z,1546982374.529 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:22:03.388Z,1546982523.388 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-01-08T21:17:03.3Z
2019-01-08T21:22:03.388Z,1546982523.388 [Default:CheckIn:Read_GPS] Stopped
2019-01-08T21:22:03.388Z,1546982523.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-01-08T21:22:08.918Z,1546982528.918 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190108T205212/Courier0010.lzma
2019-01-08T21:22:09.719Z,1546982529.719 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Courier0010.lzma.bak
2019-01-08T21:22:09.720Z,1546982529.720 [DataOverHttps](INFO): SBD MOMSN=9159224
2019-01-08T21:22:23.565Z,1546982543.565 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20190108T205212/Express0011.lzma
2019-01-08T21:22:24.349Z,1546982544.349 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Express0011.lzma.bak
2019-01-08T21:22:24.349Z,1546982544.349 [DataOverHttps](INFO): SBD MOMSN=9159226
2019-01-08T21:22:29.498Z,1546982549.498 [Default:CheckIn:Read_Iridium] Stopped
2019-01-08T21:22:29.498Z,1546982549.498 [Default:CheckIn:C.Wait] Running Loop=1
2019-01-08T21:22:29.498Z,1546982549.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-01-08T21:22:37.179Z,1546982557.179 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1001796.056198
2019-01-08T21:22:37.179Z,1546982557.179 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2019-01-08T21:22:37.179Z,1546982557.179 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-08T21:22:37.232Z,1546982557.232 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-08T21:22:37.437Z,1546982557.437 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-08T21:22:37.437Z,1546982557.437 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2019-01-08T21:22:37.786Z,1546982557.786 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-08T21:22:37.787Z,1546982557.787 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-08T21:22:37.787Z,1546982557.787 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-08T21:22:57.291Z,1546982577.291 [CommandLine](IMPORTANT): got command quit
2019-01-08T21:22:58.297Z,1546982578.297 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-08T21:22:58.297Z,1546982578.297 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:58.342Z,1546982578.342 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-01-08T21:22:58.342Z,1546982578.342 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:58.343Z,1546982578.343 [CommandLine](INFO): Join timeout helper Thread ID is 895
2019-01-08T21:22:58.343Z,1546982578.343 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-01-08T21:22:58.343Z,1546982578.343 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:58.344Z,1546982578.344 [NavChartDb](INFO): Join timeout helper Thread ID is 896
2019-01-08T21:22:58.695Z,1546982578.695 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-08T21:22:58.695Z,1546982578.695 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:58.706Z,1546982578.706 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-01-08T21:22:58.706Z,1546982578.706 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:58.707Z,1546982578.707 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 897
2019-01-08T21:22:58.946Z,1546982578.946 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-08T21:22:58.946Z,1546982578.946 [WetLabsBB2FL](INFO): Powering down
2019-01-08T21:22:58.947Z,1546982578.947 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:58.965Z,1546982578.965 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2019-01-08T21:22:58.965Z,1546982578.965 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:58.965Z,1546982578.965 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 898
2019-01-08T21:22:59.659Z,1546982579.659 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-08T21:22:59.659Z,1546982579.659 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-01-08T21:22:59.903Z,1546982579.903 [Rowe_600LCM](INFO): Powering down
2019-01-08T21:22:59.904Z,1546982579.904 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:59.910Z,1546982579.910 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-01-08T21:22:59.910Z,1546982579.910 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:22:59.911Z,1546982579.911 [Radio_Surface](INFO): Join timeout helper Thread ID is 900
2019-01-08T21:23:00.242Z,1546982580.242 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-08T21:23:00.243Z,1546982580.243 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.252Z,1546982580.252 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-01-08T21:23:00.252Z,1546982580.252 [logger ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.252Z,1546982580.252 [logger](INFO): Join timeout helper Thread ID is 901
2019-01-08T21:23:00.286Z,1546982580.286 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-08T21:23:00.286Z,1546982580.286 [logger ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.291Z,1546982580.291 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-01-08T21:23:00.291Z,1546982580.291 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.291Z,1546982580.291 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-01-08T21:23:00.291Z,1546982580.291 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.291Z,1546982580.291 [controlThread](INFO): Join timeout helper Thread ID is 902
2019-01-08T21:23:00.438Z,1546982580.438 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-08T21:23:00.438Z,1546982580.438 [controlThread](DEBUG): Uninitializing ControlThread
2019-01-08T21:23:00.439Z,1546982580.439 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-01-08T21:23:00.559Z,1546982580.559 [NAL9602](INFO): Powering down
2019-01-08T21:23:00.560Z,1546982580.560 [PNI_TCM](INFO): Powering down
2019-01-08T21:23:00.648Z,1546982580.648 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-01-08T21:23:00.649Z,1546982580.649 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-01-08T21:23:00.650Z,1546982580.650 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-01-08T21:23:00.651Z,1546982580.651 [MissionManager](INFO): Uninitializing Mission Default
2019-01-08T21:23:00.651Z,1546982580.651 [Default] Stopped
2019-01-08T21:23:00.651Z,1546982580.651 [Default](DEBUG): Aggregate::uninitialize Default
2019-01-08T21:23:00.651Z,1546982580.651 [Default:B.GoToSurface] Stopped
2019-01-08T21:23:00.651Z,1546982580.651 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-01-08T21:23:00.651Z,1546982580.651 [Default:CheckIn] Stopped
2019-01-08T21:23:00.651Z,1546982580.651 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-01-08T21:23:00.651Z,1546982580.651 [Default:CheckIn:C.Wait] Stopped
2019-01-08T21:23:00.651Z,1546982580.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-01-08T21:23:00.655Z,1546982580.655 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-01-08T21:23:00.655Z,1546982580.655 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-01-08T21:23:00.655Z,1546982580.655 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-01-08T21:23:00.656Z,1546982580.656 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-01-08T21:23:00.656Z,1546982580.656 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-01-08T21:23:00.656Z,1546982580.656 [BuoyancyServo](INFO): Powering down
2019-01-08T21:23:00.670Z,1546982580.670 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-01-08T21:23:00.670Z,1546982580.670 [ElevatorServo](INFO): Powering down
2019-01-08T21:23:00.671Z,1546982580.671 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-01-08T21:23:00.671Z,1546982580.671 [MassServo](INFO): Powering down
2019-01-08T21:23:00.672Z,1546982580.672 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-01-08T21:23:00.672Z,1546982580.672 [RudderServo](INFO): Powering down
2019-01-08T21:23:00.673Z,1546982580.673 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-01-08T21:23:00.673Z,1546982580.673 [ThrusterServo](INFO): Powering down
2019-01-08T21:23:00.674Z,1546982580.674 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-01-08T21:23:00.675Z,1546982580.675 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-01-08T21:23:00.675Z,1546982580.675 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-01-08T21:23:00.675Z,1546982580.675 [CBIT](DEBUG): Powering off loads.
2019-01-08T21:23:00.686Z,1546982580.686 [CBIT](DEBUG): Disabling WDT.
2019-01-08T21:23:00.698Z,1546982580.698 [CBIT](DEBUG): Opening all GF detection circuits.
2019-01-08T21:23:00.699Z,1546982580.699 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.789Z,1546982580.789 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.795Z,1546982580.795 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.836Z,1546982580.836 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.883Z,1546982580.883 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-01-08T21:23:00.951Z,1546982580.951 [logger ThreadHandler](INFO): Thread cancelled.