2018-08-22T23:54:02.357Z,1534982042.357 [Supervisor](DEBUG): Initializing supervisor.
2018-08-22T23:54:02.360Z,1534982042.360 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-22T23:54:02.361Z,1534982042.361 [SyncHandler](INFO): Protected caller Thread ID is 2085
2018-08-22T23:54:02.361Z,1534982042.361 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-22T23:54:02.362Z,1534982042.362 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-22T23:54:02.362Z,1534982042.362 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2086
2018-08-22T23:54:02.365Z,1534982042.365 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-22T23:54:02.377Z,1534982042.377 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-22T23:54:02.378Z,1534982042.378 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-22T23:54:02.378Z,1534982042.378 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2087
2018-08-22T23:54:02.379Z,1534982042.379 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-22T23:54:02.380Z,1534982042.380 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-22T23:54:02.380Z,1534982042.380 [logger ThreadHandler](INFO): Protected caller Thread ID is 2088
2018-08-22T23:54:02.382Z,1534982042.382 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-22T23:54:02.382Z,1534982042.382 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-22T23:54:02.384Z,1534982042.384 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-22T23:54:02.483Z,1534982042.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-22T23:54:02.484Z,1534982042.484 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-22T23:54:02.588Z,1534982042.588 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-22T23:54:02.589Z,1534982042.589 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-22T23:54:02.799Z,1534982042.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-22T23:54:02.799Z,1534982042.799 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-22T23:54:03.136Z,1534982043.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-22T23:54:03.136Z,1534982043.136 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-22T23:54:03.487Z,1534982043.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-22T23:54:03.488Z,1534982043.488 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-22T23:54:03.962Z,1534982043.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-22T23:54:03.962Z,1534982043.962 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-22T23:54:04.398Z,1534982044.398 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-22T23:54:04.399Z,1534982044.399 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-22T23:54:04.885Z,1534982044.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-22T23:54:04.886Z,1534982044.886 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-22T23:54:04.970Z,1534982044.970 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-22T23:54:05.281Z,1534982045.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-22T23:54:05.281Z,1534982045.281 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-22T23:54:05.431Z,1534982045.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-22T23:54:05.432Z,1534982045.432 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-22T23:54:05.647Z,1534982045.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-22T23:54:05.648Z,1534982045.648 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-22T23:54:05.867Z,1534982045.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-22T23:54:05.868Z,1534982045.868 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-22T23:54:05.983Z,1534982045.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-22T23:54:05.983Z,1534982045.983 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-22T23:54:06.390Z,1534982046.390 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-22T23:54:06.392Z,1534982046.392 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-08-22T23:54:06.393Z,1534982046.393 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-08-22T23:54:06.840Z,1534982046.840 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-22T23:54:06.841Z,1534982046.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-08-22T23:54:06.949Z,1534982046.949 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-08-22T23:54:07.098Z,1534982047.098 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-08-22T23:54:07.194Z,1534982047.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-08-22T23:54:07.282Z,1534982047.282 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-08-22T23:54:07.429Z,1534982047.429 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-08-22T23:54:07.616Z,1534982047.616 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-08-22T23:54:07.717Z,1534982047.717 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-08-22T23:54:07.814Z,1534982047.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-08-22T23:54:07.915Z,1534982047.915 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-08-22T23:54:08.002Z,1534982048.002 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-08-22T23:54:08.002Z,1534982048.002 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-22T23:54:08.011Z,1534982048.011 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-22T23:54:08.109Z,1534982048.109 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-22T23:54:08.110Z,1534982048.110 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-22T23:54:08.122Z,1534982048.122 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-22T23:54:08.123Z,1534982048.123 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-22T23:54:08.163Z,1534982048.163 [DepthRateCalculator] Loaded
2018-08-22T23:54:08.164Z,1534982048.164 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-22T23:54:08.170Z,1534982048.170 [PitchRateCalculator] Loaded
2018-08-22T23:54:08.170Z,1534982048.170 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-22T23:54:08.186Z,1534982048.186 [SpeedCalculator] Loaded
2018-08-22T23:54:08.186Z,1534982048.186 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-22T23:54:08.207Z,1534982048.207 [TempGradientCalculator] Loaded
2018-08-22T23:54:08.208Z,1534982048.208 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-22T23:54:08.223Z,1534982048.223 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-22T23:54:08.223Z,1534982048.223 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-22T23:54:08.229Z,1534982048.229 [YawRateCalculator] Loaded
2018-08-22T23:54:08.229Z,1534982048.229 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-22T23:54:08.269Z,1534982048.269 [ElevatorOffsetCalculator] Loaded
2018-08-22T23:54:08.270Z,1534982048.270 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-22T23:54:08.270Z,1534982048.270 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-22T23:54:08.271Z,1534982048.271 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-22T23:54:08.295Z,1534982048.295 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-22T23:54:08.296Z,1534982048.296 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-22T23:54:08.575Z,1534982048.575 [DataOverHttps] Loaded
2018-08-22T23:54:08.575Z,1534982048.575 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-22T23:54:08.600Z,1534982048.600 [Depth_Keller] Loaded
2018-08-22T23:54:08.600Z,1534982048.600 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-22T23:54:08.605Z,1534982048.605 [DropWeight] Loaded
2018-08-22T23:54:08.605Z,1534982048.605 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-22T23:54:08.704Z,1534982048.704 [NAL9602] Loaded
2018-08-22T23:54:08.704Z,1534982048.704 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-22T23:54:08.720Z,1534982048.720 [Onboard] Loaded
2018-08-22T23:54:08.720Z,1534982048.720 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-22T23:54:08.730Z,1534982048.730 [Radio_Surface] Loaded
2018-08-22T23:54:08.730Z,1534982048.730 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-22T23:54:08.731Z,1534982048.731 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B84E0
2018-08-22T23:54:08.732Z,1534982048.732 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2167
2018-08-22T23:54:08.779Z,1534982048.779 [PNI_TCM] Loaded
2018-08-22T23:54:08.779Z,1534982048.779 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-22T23:54:08.840Z,1534982048.840 [Rowe_600LCM] Loaded
2018-08-22T23:54:08.840Z,1534982048.840 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-08-22T23:54:08.841Z,1534982048.841 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407E84E0
2018-08-22T23:54:08.842Z,1534982048.842 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 2168
2018-08-22T23:54:08.842Z,1534982048.842 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-22T23:54:08.843Z,1534982048.843 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-22T23:54:08.970Z,1534982048.970 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-22T23:54:08.993Z,1534982048.993 [SBIT] Loaded
2018-08-22T23:54:08.993Z,1534982048.993 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-22T23:54:08.994Z,1534982048.994 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-22T23:54:09.006Z,1534982049.006 [IBIT] Loaded
2018-08-22T23:54:09.006Z,1534982049.006 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-22T23:54:09.009Z,1534982049.009 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-22T23:54:09.158Z,1534982049.158 [CBIT] Loaded
2018-08-22T23:54:09.159Z,1534982049.159 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-22T23:54:09.159Z,1534982049.159 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-22T23:54:09.160Z,1534982049.160 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-22T23:54:09.335Z,1534982049.335 [CTD_Seabird] Loaded
2018-08-22T23:54:09.335Z,1534982049.335 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-08-22T23:54:09.336Z,1534982049.336 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408AC4E0
2018-08-22T23:54:09.337Z,1534982049.337 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2169
2018-08-22T23:54:09.354Z,1534982049.354 [ESPComponent] Loaded
2018-08-22T23:54:09.354Z,1534982049.354 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-08-22T23:54:09.368Z,1534982049.368 [PAR_Licor] Loaded
2018-08-22T23:54:09.368Z,1534982049.368 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-22T23:54:09.418Z,1534982049.418 [WetLabsBB2FL] Loaded
2018-08-22T23:54:09.418Z,1534982049.418 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-22T23:54:09.419Z,1534982049.419 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408DC4E0
2018-08-22T23:54:09.419Z,1534982049.419 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2170
2018-08-22T23:54:09.420Z,1534982049.420 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-22T23:54:09.421Z,1534982049.421 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-22T23:54:09.656Z,1534982049.656 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-22T23:54:09.657Z,1534982049.657 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-22T23:54:09.722Z,1534982049.722 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-22T23:54:09.816Z,1534982049.816 [VerticalControl] Loaded
2018-08-22T23:54:09.817Z,1534982049.817 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-22T23:54:09.817Z,1534982049.817 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-22T23:54:09.878Z,1534982049.878 [HorizontalControl] Loaded
2018-08-22T23:54:09.878Z,1534982049.878 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-22T23:54:09.879Z,1534982049.879 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-22T23:54:09.884Z,1534982049.884 [SpeedControl] Loaded
2018-08-22T23:54:09.884Z,1534982049.884 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-22T23:54:09.885Z,1534982049.885 [LoopControl](DEBUG): Construct LoopControl.
2018-08-22T23:54:09.885Z,1534982049.885 [LoopControl] Loaded
2018-08-22T23:54:09.886Z,1534982049.886 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-22T23:54:09.886Z,1534982049.886 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-22T23:54:09.887Z,1534982049.887 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-22T23:54:09.968Z,1534982049.968 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-22T23:54:09.968Z,1534982049.968 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-22T23:54:09.969Z,1534982049.969 [StratificationFrontDetector] Loaded
2018-08-22T23:54:09.969Z,1534982049.969 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-22T23:54:09.970Z,1534982049.970 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-22T23:54:09.970Z,1534982049.970 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-22T23:54:10.068Z,1534982050.068 [BuoyancyServo] Loaded
2018-08-22T23:54:10.069Z,1534982050.069 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-22T23:54:10.080Z,1534982050.080 [ElevatorServo] Loaded
2018-08-22T23:54:10.080Z,1534982050.080 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-22T23:54:10.091Z,1534982050.091 [MassServo] Loaded
2018-08-22T23:54:10.091Z,1534982050.091 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-22T23:54:10.102Z,1534982050.102 [RudderServo] Loaded
2018-08-22T23:54:10.103Z,1534982050.103 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-22T23:54:10.114Z,1534982050.114 [ThrusterServo] Loaded
2018-08-22T23:54:10.114Z,1534982050.114 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-22T23:54:10.114Z,1534982050.114 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-22T23:54:10.115Z,1534982050.115 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-22T23:54:10.204Z,1534982050.204 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-22T23:54:10.205Z,1534982050.205 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-22T23:54:10.221Z,1534982050.221 [NavChart] Loaded
2018-08-22T23:54:10.221Z,1534982050.221 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-22T23:54:10.225Z,1534982050.225 [UniversalFixResidualReporter] Loaded
2018-08-22T23:54:10.225Z,1534982050.225 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-22T23:54:10.226Z,1534982050.226 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-22T23:54:10.229Z,1534982050.229 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-22T23:54:10.230Z,1534982050.230 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-22T23:54:10.237Z,1534982050.237 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-22T23:54:10.238Z,1534982050.238 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A354E0
2018-08-22T23:54:10.238Z,1534982050.238 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2171
2018-08-22T23:54:10.243Z,1534982050.243 [Supervisor](INFO): Main Thread ID is 796
2018-08-22T23:54:10.243Z,1534982050.243 [Supervisor](DEBUG): Running supervisor.
2018-08-22T23:54:10.243Z,1534982050.243 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2172
2018-08-22T23:54:10.247Z,1534982050.247 [controlThread ThreadHandler](INFO): Handler Thread ID is 2173
2018-08-22T23:54:10.247Z,1534982050.247 [controlThread](DEBUG): Initializing ControlThread
2018-08-22T23:54:10.248Z,1534982050.248 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-22T23:54:10.249Z,1534982050.249 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-22T23:54:10.249Z,1534982050.249 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-22T23:54:10.249Z,1534982050.249 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-22T23:54:10.250Z,1534982050.250 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-22T23:54:10.251Z,1534982050.251 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-22T23:54:10.251Z,1534982050.251 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-22T23:54:10.255Z,1534982050.255 [SBIT](INFO): Initialize SBIT Component.
2018-08-22T23:54:10.255Z,1534982050.255 [SBIT](IMPORTANT): git: 2018-08-21
2018-08-22T23:54:10.256Z,1534982050.256 [SBIT](INFO): git hash: d4ab0a1cfab12a66871bdda78458a7e977097781
2018-08-22T23:54:10.256Z,1534982050.256 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-22T23:54:10.257Z,1534982050.257 [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-22T23:54:10.258Z,1534982050.258 [SBIT](INFO): Beginning SBIT in 91.000000 seconds.
2018-08-22T23:54:10.259Z,1534982050.259 [IBIT](INFO): Initialize IBIT Component.
2018-08-22T23:54:10.260Z,1534982050.260 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-22T23:54:10.260Z,1534982050.260 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-22T23:54:10.261Z,1534982050.261 [logger ThreadHandler](INFO): Handler Thread ID is 2174
2018-08-22T23:54:10.281Z,1534982050.281 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2175
2018-08-22T23:54:10.287Z,1534982050.287 [Radio_Surface](INFO): Powering up
2018-08-22T23:54:10.293Z,1534982050.293 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 2176
2018-08-22T23:54:10.294Z,1534982050.294 [Rowe_600LCM](INFO): Initializing
2018-08-22T23:54:10.294Z,1534982050.294 [Rowe_600LCM](INFO): Checking LCM
2018-08-22T23:54:10.303Z,1534982050.303 [Rowe_600LCM](INFO): LCM OK
2018-08-22T23:54:10.304Z,1534982050.304 [Rowe_600LCM](INFO): Powering up
2018-08-22T23:54:10.309Z,1534982050.309 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2177
2018-08-22T23:54:10.310Z,1534982050.310 [CTD_Seabird](INFO): Initializing
2018-08-22T23:54:10.310Z,1534982050.310 [CTD_Seabird](INFO): Checking LCM
2018-08-22T23:54:10.311Z,1534982050.311 [CTD_Seabird](INFO): LCM OK
2018-08-22T23:54:10.311Z,1534982050.311 [CTD_Seabird](INFO): Powering up
2018-08-22T23:54:10.321Z,1534982050.321 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2178
2018-08-22T23:54:10.322Z,1534982050.322 [WetLabsBB2FL](INFO): Powering down
2018-08-22T23:54:10.349Z,1534982050.349 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2179
2018-08-22T23:54:10.354Z,1534982050.354 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000
2018-08-22T23:54:10.355Z,1534982050.355 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000
2018-08-22T23:54:10.355Z,1534982050.355 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000
2018-08-22T23:54:10.355Z,1534982050.355 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000
2018-08-22T23:54:10.355Z,1534982050.355 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000
2018-08-22T23:54:10.355Z,1534982050.355 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000
2018-08-22T23:54:10.356Z,1534982050.356 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000
2018-08-22T23:54:10.356Z,1534982050.356 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000
2018-08-22T23:54:10.369Z,1534982050.369 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-22T23:54:10.371Z,1534982050.371 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-22T23:54:10.372Z,1534982050.372 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-22T23:54:10.372Z,1534982050.372 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-22T23:54:10.374Z,1534982050.374 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-22T23:54:10.375Z,1534982050.375 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-22T23:54:10.375Z,1534982050.375 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-22T23:54:10.376Z,1534982050.376 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-22T23:54:10.376Z,1534982050.376 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-22T23:54:10.378Z,1534982050.378 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-22T23:54:10.401Z,1534982050.401 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-22T23:54:10.432Z,1534982050.432 [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-22T23:54:10.433Z,1534982050.433 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-22T23:54:10.512Z,1534982050.512 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-22T23:54:10.529Z,1534982050.529 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-22T23:54:10.531Z,1534982050.531 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-22T23:54:10.549Z,1534982050.549 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-22T23:54:10.552Z,1534982050.552 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-22T23:54:10.582Z,1534982050.582 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-22T23:54:10.601Z,1534982050.601 [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-22T23:54:10.606Z,1534982050.606 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,ESPComponent,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-22T23:54:10.639Z,1534982050.639 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-22T23:54:10.858Z,1534982050.858 [WetLabsBB2FL](FAULT): LCB fault:  Software Overcurrent.
2018-08-22T23:54:10.858Z,1534982050.858 [WetLabsBB2FL] Hardware Fault, FailCount= 1
2018-08-22T23:54:10.858Z,1534982050.858 [WetLabsBB2FL](ERROR): Hardware Fault
2018-08-22T23:54:10.887Z,1534982050.887 [ESPComponent](INFO): powering down ESP
2018-08-22T23:54:11.747Z,1534982051.747 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:11.942Z,1534982051.942 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-22T23:54:11.949Z,1534982051.949 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-22T23:54:11.956Z,1534982051.956 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-22T23:54:11.961Z,1534982051.961 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-22T23:54:11.967Z,1534982051.967 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-22T23:54:11.981Z,1534982051.981 [MassServo](DEBUG): Initializing MassServo.
2018-08-22T23:54:11.988Z,1534982051.988 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-22T23:54:11.993Z,1534982051.993 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-22T23:54:12.016Z,1534982052.016 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-22T23:54:12.017Z,1534982052.017 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-22T23:54:12.098Z,1534982052.098 [CBIT](ERROR): Hardware Fault in component: WetLabsBB2FL
2018-08-22T23:54:12.099Z,1534982052.099 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2018-08-22T23:54:12.099Z,1534982052.099 [WetLabsBB2FL] No Fault, FailCount= 1
2018-08-22T23:54:12.193Z,1534982052.193 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2018-08-22T23:54:12.193Z,1534982052.193 [WetLabsBB2FL](INFO): Powering up
2018-08-22T23:54:12.393Z,1534982052.393 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:12.612Z,1534982052.612 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:13.035Z,1534982053.035 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:13.523Z,1534982053.523 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:13.793Z,1534982053.793 [WetLabsBB2FL](INFO): Powering down
2018-08-22T23:54:13.837Z,1534982053.837 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:14.264Z,1534982054.264 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:14.678Z,1534982054.678 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-22T23:54:14.708Z,1534982054.708 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-22T23:54:14.831Z,1534982054.831 [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-22T23:54:14.874Z,1534982054.874 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-22T23:54:14.875Z,1534982054.875 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-22T23:54:14.875Z,1534982054.875 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-22T23:54:15.940Z,1534982055.940 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-22T23:54:16.128Z,1534982056.128 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-08-22T23:54:16.129Z,1534982056.129 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-08-22T23:54:16.621Z,1534982056.621 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-22T23:54:16.621Z,1534982056.621 [CTD_Seabird](INFO): Powering down
2018-08-22T23:54:38.891Z,1534982078.891 [NAL9602](INFO): Powering up NAL9602
2018-08-22T23:54:49.700Z,1534982089.700 [NAL9602](INFO): NAL9602 initialized
2018-08-22T23:55:41.766Z,1534982141.766 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-22T23:55:41.774Z,1534982141.774 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-22T23:55:52.726Z,1534982152.726 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.014286
CHAN A1 (24V): -0.013158
CHAN A2 (12V): -0.005210
CHAN A3 (5V): -0.002348
CHAN B0 (3.3V): -0.001270
CHAN B1 (3.15aV): -0.000340
CHAN B2 (3.15bV): -0.001047
CHAN B3 (GND): -0.000027
OPEN: 0.004867
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-22T23:56:10.657Z,1534982170.657 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-22T23:56:10.657Z,1534982170.657 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-22T23:56:10.657Z,1534982170.657 [Rowe_600LCM](ERROR): Communications Fault
2018-08-22T23:56:10.998Z,1534982170.998 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-22T23:56:11.061Z,1534982171.061 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-22T23:56:11.167Z,1534982171.167 [Rowe_600LCM](INFO): Powering down
2018-08-22T23:56:12.594Z,1534982172.594 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-22T23:56:12.594Z,1534982172.594 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-22T23:56:12.781Z,1534982172.781 [Rowe_600LCM](INFO): Initializing
2018-08-22T23:56:12.781Z,1534982172.781 [Rowe_600LCM](INFO): Checking LCM
2018-08-22T23:56:12.781Z,1534982172.781 [Rowe_600LCM](INFO): LCM OK
2018-08-22T23:56:12.782Z,1534982172.782 [Rowe_600LCM](INFO): Powering up
2018-08-22T23:56:16.964Z,1534982176.964 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-22T23:56:17.100Z,1534982177.100 [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-22T23:56:17.101Z,1534982177.101 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-22T23:56:17.102Z,1534982177.102 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-22T23:56:17.103Z,1534982177.103 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-22T23:56:35.368Z,1534982195.368 [SBIT](FAULT): Mass: EXPECTED:-0.018000 ACTUAL:-0.013002
2018-08-22T23:56:35.368Z,1534982195.368 [SBIT](FAULT): Control surface position failure.
2018-08-22T23:56:35.769Z,1534982195.769 [SBIT](CRITICAL): SBIT FAILED
2018-08-22T23:56:35.819Z,1534982195.819 [CommandLine](IMPORTANT): got command configSet list
2018-08-22T23:56:35.819Z,1534982195.819 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-22T23:56:35.820Z,1534982195.820 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2018-08-22T23:56:35.820Z,1534982195.820 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2018-08-22T23:56:35.820Z,1534982195.820 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-08-22T23:56:35.820Z,1534982195.820 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 1.000000 microgram_per_liter;

2018-08-22T23:56:35.820Z,1534982195.820 [CommandLine](IMPORTANT): IBIT.batteryHibernationTimeout=1 minute;

2018-08-22T23:56:35.821Z,1534982195.821 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold=12 count;

2018-08-22T23:56:35.821Z,1534982195.821 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2018-08-22T23:56:35.821Z,1534982195.821 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1.8 centimeter;

2018-08-22T23:56:35.827Z,1534982195.827 [CommandLine](FAULT): Scheduling is paused
2018-08-22T23:56:35.828Z,1534982195.828 [CBIT](INFO): Critical error at 20180822T235635
2018-08-22T23:56:35.828Z,1534982195.828 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-08-22T23:56:36.186Z,1534982196.186 [MissionManager](IMPORTANT): Started mission Startup
2018-08-22T23:56:36.186Z,1534982196.186 [Startup] Running Loop=1
2018-08-22T23:56:36.187Z,1534982196.187 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-22T23:56:36.187Z,1534982196.187 [Startup:A.GoToSurface] Running Loop=1
2018-08-22T23:56:36.187Z,1534982196.187 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-22T23:56:36.187Z,1534982196.187 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-22T23:56:36.188Z,1534982196.188 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-22T23:56:36.188Z,1534982196.188 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-22T23:56:36.189Z,1534982196.189 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-22T23:56:36.189Z,1534982196.189 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-22T23:56:36.199Z,1534982196.199 [Startup:StartupSatComms] Running Loop=1
2018-08-22T23:56:36.200Z,1534982196.200 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-22T23:56:36.200Z,1534982196.200 [Startup:StartupSatComms:A] Running Loop=1
2018-08-22T23:56:36.570Z,1534982196.570 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-22T23:57:10.555Z,1534982230.555 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-22T23:57:10.555Z,1534982230.555 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-08-22T23:57:10.556Z,1534982230.556 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-22T23:57:10.623Z,1534982230.623 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-22T23:57:10.987Z,1534982230.987 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-22T23:57:10.987Z,1534982230.987 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-08-22T23:57:11.392Z,1534982231.392 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-22T23:57:11.392Z,1534982231.392 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-22T23:57:11.393Z,1534982231.393 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-22T23:57:36.561Z,1534982256.561 [Startup:StartupSatComms:A](INFO): Timed out from 2018-08-22T23:56:36.2Z
2018-08-22T23:57:36.561Z,1534982256.561 [Startup:StartupSatComms:A] Stopped
2018-08-22T23:57:36.561Z,1534982256.561 [Startup:StartupSatComms:B] Running Loop=1
2018-08-22T23:57:36.962Z,1534982256.962 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-22T23:58:12.879Z,1534982292.879 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-22T23:58:12.879Z,1534982292.879 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-22T23:58:12.879Z,1534982292.879 [Rowe_600LCM](ERROR): Communications Fault
2018-08-22T23:58:13.008Z,1534982293.008 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-22T23:58:13.285Z,1534982293.285 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-22T23:58:13.502Z,1534982293.502 [Rowe_600LCM](INFO): Powering down
2018-08-22T23:58:14.984Z,1534982294.984 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-22T23:58:14.984Z,1534982294.984 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-22T23:58:15.117Z,1534982295.117 [Rowe_600LCM](INFO): Initializing
2018-08-22T23:58:15.117Z,1534982295.117 [Rowe_600LCM](INFO): Checking LCM
2018-08-22T23:58:15.117Z,1534982295.117 [Rowe_600LCM](INFO): LCM OK
2018-08-22T23:58:15.118Z,1534982295.118 [Rowe_600LCM](INFO): Powering up
2018-08-22T23:58:19.244Z,1534982299.244 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-22T23:58:19.325Z,1534982299.325 [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-22T23:58:19.326Z,1534982299.326 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-22T23:58:19.327Z,1534982299.327 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-22T23:58:19.328Z,1534982299.328 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-22T23:58:36.582Z,1534982316.582 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-22T23:57:36.6Z
2018-08-22T23:58:36.582Z,1534982316.582 [Startup:StartupSatComms:B] Stopped
2018-08-22T23:58:36.582Z,1534982316.582 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-22T23:58:36.582Z,1534982316.582 [Startup:StartupSatComms] Stopped
2018-08-22T23:58:36.582Z,1534982316.582 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-22T23:58:36.583Z,1534982316.583 [Startup](INFO): Completed Startup
2018-08-22T23:58:36.584Z,1534982316.584 [MissionManager](INFO): Startup is completed.
2018-08-22T23:58:36.584Z,1534982316.584 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-22T23:58:36.584Z,1534982316.584 [Startup] Stopped
2018-08-22T23:58:36.584Z,1534982316.584 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-22T23:58:36.584Z,1534982316.584 [Startup:A.GoToSurface] Stopped
2018-08-22T23:58:36.584Z,1534982316.584 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-22T23:58:36.982Z,1534982316.982 [MissionManager](IMPORTANT): Started mission Default
2018-08-22T23:58:36.982Z,1534982316.982 [Default] Running Loop=1
2018-08-22T23:58:36.982Z,1534982316.982 [Default](DEBUG): Aggregate::initialize Default
2018-08-22T23:58:36.982Z,1534982316.982 [Default:B.GoToSurface] Running Loop=1
2018-08-22T23:58:36.982Z,1534982316.982 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-22T23:58:36.983Z,1534982316.983 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-22T23:58:36.983Z,1534982316.983 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-22T23:58:36.983Z,1534982316.983 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-22T23:58:36.984Z,1534982316.984 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-22T23:58:36.984Z,1534982316.984 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-22T23:58:36.984Z,1534982316.984 [Default:A.Wait] Running Loop=1
2018-08-22T23:58:36.985Z,1534982316.985 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-22T23:58:50.171Z,1534982330.171 [Default:A.Wait](INFO): Done Waiting.
2018-08-22T23:58:50.172Z,1534982330.172 [Default:A.Wait] Stopped
2018-08-22T23:58:50.172Z,1534982330.172 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-22T23:58:50.560Z,1534982330.560 [Default:CheckIn] Running Loop=1
2018-08-22T23:58:50.560Z,1534982330.560 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-22T23:58:50.560Z,1534982330.560 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-22T23:58:50.967Z,1534982330.967 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-22T23:59:52.517Z,1534982392.517 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-23T00:00:11.773Z,1534982411.773 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:00:11.773Z,1534982411.773 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-08-23T00:00:11.773Z,1534982411.773 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:00:11.831Z,1534982411.831 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:00:12.202Z,1534982412.202 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:00:12.202Z,1534982412.202 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-08-23T00:00:12.556Z,1534982412.556 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:00:12.556Z,1534982412.556 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:00:12.556Z,1534982412.556 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:00:15.833Z,1534982415.833 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:00:15.833Z,1534982415.833 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T00:00:15.833Z,1534982415.833 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:00:16.188Z,1534982416.188 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:00:16.237Z,1534982416.237 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:00:16.353Z,1534982416.353 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:00:20.521Z,1534982420.521 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:00:20.522Z,1534982420.522 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T00:00:20.797Z,1534982420.797 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:00:20.797Z,1534982420.797 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:00:20.798Z,1534982420.798 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:00:20.798Z,1534982420.798 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:00:21.735Z,1534982421.735 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004343
2018-08-23T00:00:24.977Z,1534982424.977 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:00:25.100Z,1534982425.100 [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-23T00:00:25.103Z,1534982425.103 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:00:25.104Z,1534982425.104 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:00:25.105Z,1534982425.105 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:02:21.241Z,1534982541.241 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:02:21.241Z,1534982541.241 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T00:02:21.241Z,1534982541.241 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:02:21.497Z,1534982541.497 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:02:21.645Z,1534982541.645 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:02:21.808Z,1534982541.808 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:02:23.091Z,1534982543.091 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:02:23.091Z,1534982543.091 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T00:02:23.425Z,1534982543.425 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:02:23.425Z,1534982543.425 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:02:23.426Z,1534982543.426 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:02:23.426Z,1534982543.426 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:02:27.598Z,1534982547.598 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:02:27.668Z,1534982547.668 [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-23T00:02:27.669Z,1534982547.669 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:02:27.670Z,1534982547.670 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:02:27.671Z,1534982547.671 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:03:12.647Z,1534982592.647 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:03:12.648Z,1534982592.648 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-08-23T00:03:12.648Z,1534982592.648 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:03:12.690Z,1534982592.690 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:03:13.088Z,1534982593.088 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:03:13.088Z,1534982593.088 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-08-23T00:03:13.456Z,1534982593.456 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:03:13.456Z,1534982593.456 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:03:13.477Z,1534982593.477 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:03:50.865Z,1534982630.865 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-22T23:58:50.6Z
2018-08-23T00:03:50.865Z,1534982630.865 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T00:03:50.865Z,1534982630.865 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T00:03:51.265Z,1534982631.265 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-23T00:03:59.187Z,1534982639.187 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T215714/Courier0033.lzma
2018-08-23T00:04:00.385Z,1534982640.385 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Courier0033.lzma.bak
2018-08-23T00:04:00.385Z,1534982640.385 [DataOverHttps](INFO): SBD MOMSN=8436658
2018-08-23T00:04:11.149Z,1534982651.149 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20180822T235402/Courier0000.lzma
2018-08-23T00:04:13.246Z,1534982653.246 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Courier0000.lzma.bak
2018-08-23T00:04:13.246Z,1534982653.246 [DataOverHttps](INFO): SBD MOMSN=8436660
2018-08-23T00:04:23.665Z,1534982663.665 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T235402/Courier0004.lzma
2018-08-23T00:04:24.217Z,1534982664.217 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:04:24.217Z,1534982664.217 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T00:04:24.217Z,1534982664.217 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:04:24.463Z,1534982664.463 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Courier0004.lzma.bak
2018-08-23T00:04:24.463Z,1534982664.463 [DataOverHttps](INFO): SBD MOMSN=8436664
2018-08-23T00:04:24.621Z,1534982664.621 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:04:24.671Z,1534982664.671 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:04:24.672Z,1534982664.672 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T00:04:24.787Z,1534982664.787 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:04:35.122Z,1534982675.122 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20180822T215714/Express0034.lzma
2018-08-23T00:04:36.320Z,1534982676.320 [DataOverHttps](INFO): Moved sent file to Logs/20180822T215714/Express0034.lzma.bak
2018-08-23T00:04:36.320Z,1534982676.320 [DataOverHttps](INFO): SBD MOMSN=8436666
2018-08-23T00:04:47.005Z,1534982687.005 [DataOverHttps](INFO): Sending 1042 bytes from file Logs/20180822T235402/Express0001.lzma
2018-08-23T00:04:48.991Z,1534982688.991 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Express0001.lzma.bak
2018-08-23T00:04:48.991Z,1534982688.991 [DataOverHttps](INFO): SBD MOMSN=8436671
2018-08-23T00:04:54.502Z,1534982694.502 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-23T00:04:54.502Z,1534982694.502 [NAL9602] Data Fault, FailCount= 1
2018-08-23T00:04:54.502Z,1534982694.502 [NAL9602](ERROR): Data Fault
2018-08-23T00:04:54.605Z,1534982694.605 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-23T00:04:54.897Z,1534982694.897 [NAL9602](INFO): Powering down
2018-08-23T00:04:55.743Z,1534982695.743 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-23T00:04:55.743Z,1534982695.743 [NAL9602] No Fault, FailCount= 1
2018-08-23T00:04:59.655Z,1534982699.655 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20180822T235402/Express0005.lzma
2018-08-23T00:05:00.847Z,1534982700.847 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Express0005.lzma.bak
2018-08-23T00:05:00.847Z,1534982700.847 [DataOverHttps](INFO): SBD MOMSN=8436695
2018-08-23T00:05:02.295Z,1534982702.295 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T00:05:02.295Z,1534982702.295 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T00:05:02.295Z,1534982702.295 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T00:05:25.109Z,1534982725.109 [NAL9602](INFO): Powering up NAL9602
2018-08-23T00:05:36.314Z,1534982736.314 [NAL9602](INFO): NAL9602 initialized
2018-08-23T00:06:13.551Z,1534982773.551 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:06:13.551Z,1534982773.551 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2018-08-23T00:06:13.551Z,1534982773.551 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:06:13.564Z,1534982773.564 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:06:13.925Z,1534982773.925 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:06:13.925Z,1534982773.925 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2018-08-23T00:06:14.308Z,1534982774.308 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:06:14.308Z,1534982774.308 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:06:14.309Z,1534982774.309 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:07:11.036Z,1534982831.036 [DataOverHttps](IMPORTANT): SBD MTMSN=20180823T000615
2018-08-23T00:07:15.426Z,1534982835.426 [DataOverHttps](INFO): Received command:sched asap "load Maintenance/sample.xml;set sample.MissionTimeout 3 hour;set sample.Depth 0 meter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" 3e890 1 2
2018-08-23T00:07:15.457Z,1534982835.457 [CommandLine](IMPORTANT): got command schedule asap "load Maintenance/sample.xml;set sample.MissionTimeout 3 hour;set sample.Depth 0 meter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" 3e890 1 2.000000
2018-08-23T00:07:15.458Z,1534982835.458 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=3e890
2018-08-23T00:07:15.459Z,1534982835.459 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='3e890'): "load Maintenance/sample.xml;set sample.MissionTimeout 3 hour;set sample.Depth 0 meter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.Speed 0 meter_per_second" ASAP
2018-08-23T00:07:16.224Z,1534982836.224 [DataOverHttps](IMPORTANT): SBD MTMSN=20180823T000621
2018-08-23T00:07:20.587Z,1534982840.587 [DataOverHttps](INFO): Received command:sched asap "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " 3e890 2 2
2018-08-23T00:07:20.658Z,1534982840.658 [CommandLine](IMPORTANT): got command schedule asap "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " 3e890 2 2.000000
2018-08-23T00:07:20.658Z,1534982840.658 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=3e890
2018-08-23T00:07:20.659Z,1534982840.659 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='3e890'): "set sample:SampleAtDepth.SpeedApproachingDepth 0 meter_per_second;set sample:SampleAtDepth.SpeedSamplingAtDepth 0 meter_per_second;set sample:SampleAtDepth.TargetDepth 0 meter;run " ASAP
2018-08-23T00:07:20.861Z,1534982840.861 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2018-08-23T00:07:20.861Z,1534982840.861 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2018-08-23T00:07:20.907Z,1534982840.907 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2018-08-23T00:07:20.910Z,1534982840.910 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2018-08-23T00:07:20.913Z,1534982840.913 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2018-08-23T00:07:20.916Z,1534982840.916 [MissionManager](INFO): DefineArg sample.SpeedApproachingTarget = 0.000000 m/s
2018-08-23T00:07:20.919Z,1534982840.919 [MissionManager](INFO): DefineArg sample.SpeedSampling = 0.000000 m/s
2018-08-23T00:07:20.922Z,1534982840.922 [MissionManager](INFO): DefineArg sample.RudderAngleSpiralOrDonut = 13.000000 arcdeg
2018-08-23T00:07:20.925Z,1534982840.925 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2018-08-23T00:07:20.926Z,1534982840.926 [sample:A.Pitch](DEBUG): Construct.
2018-08-23T00:07:20.931Z,1534982840.931 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2018-08-23T00:07:21.191Z,1534982841.191 [MissionManager](INFO): DefineArg sample:SampleAtDepth.Speed = 1.000000 m/s
2018-08-23T00:07:21.207Z,1534982841.207 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SpeedApproachingDepth = 1.000000 m/s
2018-08-23T00:07:21.210Z,1534982841.210 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SpeedSamplingAtDepth = 1.000000 m/s
2018-08-23T00:07:21.221Z,1534982841.221 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RudderAngleInSpiralOrDonut = 13.000000 arcdeg
2018-08-23T00:07:21.224Z,1534982841.224 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2018-08-23T00:07:21.227Z,1534982841.227 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s
2018-08-23T00:07:21.229Z,1534982841.229 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2018-08-23T00:07:21.232Z,1534982841.232 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2018-08-23T00:07:21.247Z,1534982841.247 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool
2018-08-23T00:07:21.250Z,1534982841.250 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool
2018-08-23T00:07:21.265Z,1534982841.265 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2018-08-23T00:07:21.269Z,1534982841.269 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2018-08-23T00:07:21.272Z,1534982841.272 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 199.999995 cc
2018-08-23T00:07:21.291Z,1534982841.291 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Construct.
2018-08-23T00:07:21.299Z,1534982841.299 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Construct Buoyancy.
2018-08-23T00:07:21.302Z,1534982841.302 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point](DEBUG): Construct.
2018-08-23T00:07:21.329Z,1534982841.329 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Construct.
2018-08-23T00:07:21.332Z,1534982841.332 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point](DEBUG): Construct.
2018-08-23T00:07:21.355Z,1534982841.355 [sample:SampleAtDepth:D.Pitch](DEBUG): Construct.
2018-08-23T00:07:21.361Z,1534982841.361 [sample:SampleAtDepth:D.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-08-23T00:07:21.400Z,1534982841.400 [sample:SampleAtDepth:SampleWrapper:B.Wait](DEBUG): Construct Wait.
2018-08-23T00:07:21.451Z,1534982841.451 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-08-23T00:07:21.462Z,1534982841.462 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2018-08-23T00:07:21.463Z,1534982841.463 [MissionManager](ERROR): Slate does not contain celsius
2018-08-23T00:07:21.476Z,1534982841.476 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-08-23T00:07:21.504Z,1534982841.504 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2018-08-23T00:07:21.504Z,1534982841.504 [MissionManager](ERROR): Slate does not contain celsius
2018-08-23T00:07:21.560Z,1534982841.560 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="SpeedApproachingTarget"><Description>
        Vehicle speed when approaching the target depth. Initialized to zero.
    </Description><Units:meter_per_second/><Value>0</Value></DefineArg>

    <DefineArg Name="SpeedSampling"><Description>
        Vehicle speed during sampling: 0.0 for drift mode (prop off); 1.0 for
        donut mode (prop on). Initialized to zero.
    </Description><Units:meter_per_second/><Value>0</Value></DefineArg>

    <DefineArg Name="RudderAngleSpiralOrDonut"><Description>
        Rudder angle during spiral or donut, but not in drift mode.
    </Description><Units:degree/><Value>13</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Insert Filename="Insert/SampleAtDepth.xml"/>

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SpeedApproachingDepth"/><Arg Name="SpeedApproachingTarget"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SpeedSamplingAtDepth"/><Arg Name="SpeedSampling"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:RudderAngleInSpiralOrDonut"/><Arg Name="RudderAngleSpiralOrDonut"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2018-08-23T00:07:21.560Z,1534982841.560 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2018-08-23T00:07:26.864Z,1534982846.864 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 3.000000 hour
2018-08-23T00:07:26.865Z,1534982846.865 [CommandLine](IMPORTANT): got command set sample.Depth 0.000000 meter
2018-08-23T00:07:26.866Z,1534982846.866 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 3.000000 second
2018-08-23T00:07:26.866Z,1534982846.866 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.Speed 0.000000 meter_per_second
2018-08-23T00:07:33.299Z,1534982853.299 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SpeedApproachingDepth 0.000000 meter_per_second
2018-08-23T00:07:33.300Z,1534982853.300 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SpeedSamplingAtDepth 0.000000 meter_per_second
2018-08-23T00:07:33.301Z,1534982853.301 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 0.000000 meter
2018-08-23T00:07:33.301Z,1534982853.301 [CommandLine](IMPORTANT): got command run 
2018-08-23T00:07:33.303Z,1534982853.303 [CommandLine](IMPORTANT): Running 
2018-08-23T00:07:33.431Z,1534982853.431 [Default] Stopped
2018-08-23T00:07:33.431Z,1534982853.431 [Default](DEBUG): Aggregate::uninitialize Default
2018-08-23T00:07:33.431Z,1534982853.431 [Default:B.GoToSurface] Stopped
2018-08-23T00:07:33.431Z,1534982853.431 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-23T00:07:33.431Z,1534982853.431 [Default:CheckIn] Stopped
2018-08-23T00:07:33.431Z,1534982853.431 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T00:07:33.431Z,1534982853.431 [Default:CheckIn:C.Wait] Stopped
2018-08-23T00:07:33.431Z,1534982853.431 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T00:07:33.432Z,1534982853.432 [MissionManager](IMPORTANT): Started mission sample
2018-08-23T00:07:33.432Z,1534982853.432 [sample] Running Loop=1
2018-08-23T00:07:33.432Z,1534982853.432 [sample](DEBUG): Aggregate::initialize sample
2018-08-23T00:07:33.432Z,1534982853.432 [sample:A.Pitch] Running Loop=1
2018-08-23T00:07:33.432Z,1534982853.432 [sample:A.Pitch](DEBUG): Initialize.
2018-08-23T00:07:33.437Z,1534982853.437 [sample:C] Running Loop=1
2018-08-23T00:07:33.439Z,1534982853.439 [sample:C] Stopped
2018-08-23T00:07:33.439Z,1534982853.439 [sample:D] Running Loop=1
2018-08-23T00:07:33.439Z,1534982853.439 [sample:A.Pitch] Running Loop=1
2018-08-23T00:07:33.846Z,1534982853.846 [sample:D] Stopped
2018-08-23T00:07:33.846Z,1534982853.846 [sample:E] Running Loop=1
2018-08-23T00:07:34.245Z,1534982854.245 [sample:E] Stopped
2018-08-23T00:07:34.245Z,1534982854.245 [sample:F] Running Loop=1
2018-08-23T00:07:34.623Z,1534982854.623 [sample:F] Stopped
2018-08-23T00:07:34.624Z,1534982854.624 [sample:G] Running Loop=1
2018-08-23T00:07:35.053Z,1534982855.053 [sample:G] Stopped
2018-08-23T00:07:35.053Z,1534982855.053 [sample:SampleRepeater] Running Loop=1
2018-08-23T00:07:35.053Z,1534982855.053 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2018-08-23T00:07:35.053Z,1534982855.053 [sample:SampleRepeater:Sample] Running Loop=1
2018-08-23T00:07:35.053Z,1534982855.053 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2018-08-23T00:07:35.457Z,1534982855.457 [sample:SampleAtDepth] Running Loop=1
2018-08-23T00:07:35.457Z,1534982855.457 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2018-08-23T00:07:35.457Z,1534982855.457 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode] Running Loop=1
2018-08-23T00:07:35.457Z,1534982855.457 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode
2018-08-23T00:07:35.457Z,1534982855.457 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed] Running Loop=1
2018-08-23T00:07:35.457Z,1534982855.457 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Initialize.
2018-08-23T00:07:35.457Z,1534982855.457 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy] Running Loop=1
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point] Running Loop=1
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point](DEBUG): Initialize.
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Running Loop=1
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetZeroRudderInDriftMode](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetZeroRudderInDriftMode
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Running Loop=1
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Initialize.
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Running Loop=1
2018-08-23T00:07:35.458Z,1534982855.458 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point](DEBUG): Initialize.
2018-08-23T00:07:35.459Z,1534982855.459 [sample:SampleAtDepth:D.Pitch] Running Loop=1
2018-08-23T00:07:35.459Z,1534982855.459 [sample:SampleAtDepth:D.Pitch](DEBUG): Initialize.
2018-08-23T00:07:35.459Z,1534982855.459 [sample:SampleAtDepth:SetSpeedApproachDepth] Running Loop=1
2018-08-23T00:07:35.459Z,1534982855.459 [sample:SampleAtDepth:SetSpeedApproachDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth:SetSpeedApproachDepth
2018-08-23T00:07:35.459Z,1534982855.459 [sample:SampleAtDepth:SetSpeedApproachDepth:A] Running Loop=1
2018-08-23T00:07:35.474Z,1534982855.474 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Running Loop=1
2018-08-23T00:07:35.474Z,1534982855.474 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Running Loop=1
2018-08-23T00:07:35.483Z,1534982855.483 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Running Loop=1
2018-08-23T00:07:35.492Z,1534982855.492 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode] Stopped
2018-08-23T00:07:35.492Z,1534982855.492 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode
2018-08-23T00:07:35.492Z,1534982855.492 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed] Stopped
2018-08-23T00:07:35.492Z,1534982855.492 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:A.SetSpeed](DEBUG): Uninitialize.
2018-08-23T00:07:35.492Z,1534982855.492 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy] Stopped
2018-08-23T00:07:35.492Z,1534982855.492 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-08-23T00:07:35.497Z,1534982855.497 [sample:SampleAtDepth:SetNeutralBuoyancyNonZeroRudderInSpiralOrDonutMode:C.Point] Stopped
2018-08-23T00:07:35.497Z,1534982855.497 [sample:SampleAtDepth:SetSpeedApproachDepth:A](INFO): Moving to 0.000000 m 
2018-08-23T00:07:35.499Z,1534982855.499 [sample:SampleAtDepth:SetSpeedApproachDepth:A] Stopped
2018-08-23T00:07:35.499Z,1534982855.499 [sample:SampleAtDepth:SetSpeedApproachDepth:B] Running Loop=1
2018-08-23T00:07:35.855Z,1534982855.855 [sample:SampleAtDepth:SetSpeedApproachDepth:B] Stopped
2018-08-23T00:07:35.855Z,1534982855.855 [sample:SampleAtDepth:SetSpeedApproachDepth](INFO): Completed sample:SampleAtDepth:SetSpeedApproachDepth
2018-08-23T00:07:35.855Z,1534982855.855 [sample:SampleAtDepth:SetSpeedApproachDepth] Stopped
2018-08-23T00:07:35.855Z,1534982855.855 [sample:SampleAtDepth:SetSpeedApproachDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetSpeedApproachDepth
2018-08-23T00:09:14.448Z,1534982954.448 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:09:14.448Z,1534982954.448 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2018-08-23T00:09:14.448Z,1534982954.448 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:09:14.463Z,1534982954.463 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:09:14.901Z,1534982954.901 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:09:14.901Z,1534982954.901 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2018-08-23T00:09:15.259Z,1534982955.259 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:09:15.260Z,1534982955.260 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:09:15.260Z,1534982955.260 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:12:15.265Z,1534983135.265 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:12:15.265Z,1534983135.265 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2018-08-23T00:12:15.265Z,1534983135.265 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:12:15.293Z,1534983135.293 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:12:15.678Z,1534983135.678 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:12:15.678Z,1534983135.678 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2018-08-23T00:12:16.065Z,1534983136.065 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:12:16.066Z,1534983136.066 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:12:16.066Z,1534983136.066 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:12:57.234Z,1534983177.234 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.385622 seconds old.
2018-08-23T00:12:57.646Z,1534983177.646 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.797891 seconds old.
2018-08-23T00:12:58.043Z,1534983178.043 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.194465 seconds old.
2018-08-23T00:12:58.451Z,1534983178.451 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.602942 seconds old.
2018-08-23T00:12:58.830Z,1534983178.830 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.981852 seconds old.
2018-08-23T00:12:59.238Z,1534983179.238 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.389510 seconds old.
2018-08-23T00:12:59.632Z,1534983179.632 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.783605 seconds old.
2018-08-23T00:13:00.048Z,1534983180.048 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.199663 seconds old.
2018-08-23T00:14:24.446Z,1534983264.446 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:14:24.446Z,1534983264.446 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T00:14:24.637Z,1534983264.637 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:14:24.638Z,1534983264.638 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:14:24.638Z,1534983264.638 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:14:24.638Z,1534983264.638 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:14:28.832Z,1534983268.832 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:14:28.940Z,1534983268.940 [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-23T00:14:28.942Z,1534983268.942 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:14:28.943Z,1534983268.943 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:14:28.944Z,1534983268.944 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:14:48.866Z,1534983288.866 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2018-08-23T00:15:16.133Z,1534983316.133 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:15:16.133Z,1534983316.133 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2018-08-23T00:15:16.133Z,1534983316.133 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:15:16.147Z,1534983316.147 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:15:16.556Z,1534983316.556 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:15:16.556Z,1534983316.556 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2018-08-23T00:15:16.905Z,1534983316.905 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:15:16.905Z,1534983316.905 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:15:16.906Z,1534983316.906 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:15:38.690Z,1534983338.690 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-23T00:15:38.690Z,1534983338.690 [NAL9602] Data Fault, FailCount= 2
2018-08-23T00:15:38.690Z,1534983338.690 [NAL9602](ERROR): Data Fault
2018-08-23T00:15:38.775Z,1534983338.775 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-23T00:15:39.086Z,1534983339.086 [NAL9602](INFO): Powering down
2018-08-23T00:15:39.970Z,1534983339.970 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-23T00:15:39.970Z,1534983339.970 [NAL9602] No Fault, FailCount= 2
2018-08-23T00:16:09.490Z,1534983369.490 [NAL9602](INFO): Powering up NAL9602
2018-08-23T00:16:20.687Z,1534983380.687 [NAL9602](INFO): NAL9602 initialized
2018-08-23T00:16:25.345Z,1534983385.345 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:16:25.345Z,1534983385.345 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T00:16:25.345Z,1534983385.345 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:16:25.749Z,1534983385.749 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:16:25.914Z,1534983385.914 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:16:26.509Z,1534983386.509 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:16:26.722Z,1534983386.722 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-23T00:16:26.722Z,1534983386.722 [Rowe_600LCM] Hardware Fault, FailCount= 1
2018-08-23T00:16:26.722Z,1534983386.722 [Rowe_600LCM](ERROR): Hardware Fault
2018-08-23T00:16:27.417Z,1534983387.417 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:16:27.417Z,1534983387.417 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T00:16:27.529Z,1534983387.529 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:16:27.530Z,1534983387.530 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:16:27.530Z,1534983387.530 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:16:27.530Z,1534983387.530 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:16:31.653Z,1534983391.653 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:16:31.712Z,1534983391.712 [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-23T00:16:31.719Z,1534983391.719 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:16:31.720Z,1534983391.720 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:16:31.721Z,1534983391.721 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:18:17.172Z,1534983497.172 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:18:17.172Z,1534983497.172 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2018-08-23T00:18:17.172Z,1534983497.172 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:18:17.187Z,1534983497.187 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:18:17.588Z,1534983497.588 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:18:17.588Z,1534983497.588 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2018-08-23T00:18:17.975Z,1534983497.975 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:18:17.976Z,1534983497.976 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:18:17.976Z,1534983497.976 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:18:27.748Z,1534983507.748 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:18:27.748Z,1534983507.748 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T00:18:27.748Z,1534983507.748 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:18:28.095Z,1534983508.095 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:18:28.153Z,1534983508.153 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:18:28.245Z,1534983508.245 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:18:29.706Z,1534983509.706 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:18:29.706Z,1534983509.706 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T00:18:29.861Z,1534983509.861 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:18:29.861Z,1534983509.861 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:18:29.862Z,1534983509.862 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:18:29.862Z,1534983509.862 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:18:33.991Z,1534983513.991 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:18:34.149Z,1534983514.149 [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-23T00:18:34.150Z,1534983514.150 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:18:34.150Z,1534983514.150 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:18:34.151Z,1534983514.151 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:20:29.931Z,1534983629.931 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:20:29.932Z,1534983629.932 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T00:20:29.932Z,1534983629.932 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:20:30.066Z,1534983630.066 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:20:30.337Z,1534983630.337 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:20:30.544Z,1534983630.544 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:20:32.056Z,1534983632.056 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:20:32.056Z,1534983632.056 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T00:20:32.157Z,1534983632.157 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:20:32.157Z,1534983632.157 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:20:32.157Z,1534983632.157 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:20:32.157Z,1534983632.157 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:20:36.284Z,1534983636.284 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:20:36.342Z,1534983636.342 [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-23T00:20:36.343Z,1534983636.343 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:20:36.344Z,1534983636.344 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:20:36.345Z,1534983636.345 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:21:18.027Z,1534983678.027 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:21:18.027Z,1534983678.027 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2018-08-23T00:21:18.027Z,1534983678.027 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:21:18.044Z,1534983678.044 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:21:18.430Z,1534983678.430 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:21:18.430Z,1534983678.430 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2018-08-23T00:21:18.832Z,1534983678.832 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:21:18.832Z,1534983678.832 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:21:18.833Z,1534983678.833 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:22:32.889Z,1534983752.889 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:22:32.889Z,1534983752.889 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T00:22:32.889Z,1534983752.889 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:22:33.232Z,1534983753.232 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:22:33.293Z,1534983753.293 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:22:33.389Z,1534983753.389 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:22:34.783Z,1534983754.783 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:22:34.783Z,1534983754.783 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T00:22:35.005Z,1534983755.005 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:22:35.005Z,1534983755.005 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:22:35.006Z,1534983755.006 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:22:35.006Z,1534983755.006 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:22:39.183Z,1534983759.183 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:22:39.315Z,1534983759.315 [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-23T00:22:39.316Z,1534983759.316 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:22:39.317Z,1534983759.317 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:22:39.318Z,1534983759.318 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:24:18.883Z,1534983858.883 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:24:18.883Z,1534983858.883 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2018-08-23T00:24:18.883Z,1534983858.883 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:24:18.898Z,1534983858.898 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:24:19.306Z,1534983859.306 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:24:19.306Z,1534983859.306 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2018-08-23T00:24:19.691Z,1534983859.691 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:24:19.692Z,1534983859.692 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:24:19.692Z,1534983859.692 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:24:35.320Z,1534983875.320 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:24:35.320Z,1534983875.320 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T00:24:35.320Z,1534983875.320 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:24:35.463Z,1534983875.463 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:24:35.463Z,1534983875.463 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T00:24:35.725Z,1534983875.725 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:24:35.911Z,1534983875.911 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:26:22.139Z,1534983982.139 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-23T00:26:22.139Z,1534983982.139 [NAL9602] Data Fault, FailCount= 3
2018-08-23T00:26:22.139Z,1534983982.139 [NAL9602](ERROR): Data Fault
2018-08-23T00:26:22.223Z,1534983982.223 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-23T00:26:25.231Z,1534983985.231 [NAL9602](INFO): Powering down
2018-08-23T00:26:25.793Z,1534983985.793 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-23T00:26:25.793Z,1534983985.793 [NAL9602] No Fault, FailCount= 3
2018-08-23T00:26:55.326Z,1534984015.326 [NAL9602](INFO): Powering up NAL9602
2018-08-23T00:27:06.531Z,1534984026.531 [NAL9602](INFO): NAL9602 initialized
2018-08-23T00:27:19.785Z,1534984039.785 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:27:19.785Z,1534984039.785 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 11
2018-08-23T00:27:19.785Z,1534984039.785 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:27:19.837Z,1534984039.837 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:27:20.225Z,1534984040.225 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:27:20.225Z,1534984040.225 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 11
2018-08-23T00:27:20.588Z,1534984040.588 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:27:20.588Z,1534984040.588 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:27:20.589Z,1534984040.589 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:30:20.860Z,1534984220.860 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:30:20.861Z,1534984220.861 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 12
2018-08-23T00:30:20.861Z,1534984220.861 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:30:20.904Z,1534984220.904 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:30:21.269Z,1534984221.269 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:30:21.269Z,1534984221.269 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 12
2018-08-23T00:30:21.668Z,1534984221.668 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:30:21.669Z,1534984221.669 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:30:21.669Z,1534984221.669 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:33:22.073Z,1534984402.073 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:33:22.073Z,1534984402.073 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 13
2018-08-23T00:33:22.073Z,1534984402.073 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:33:22.121Z,1534984402.121 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:33:22.495Z,1534984402.495 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:33:22.495Z,1534984402.495 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 13
2018-08-23T00:33:22.852Z,1534984402.852 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:33:22.852Z,1534984402.852 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:33:22.852Z,1534984402.852 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:34:35.608Z,1534984475.608 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:34:35.608Z,1534984475.608 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T00:34:35.805Z,1534984475.805 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:34:35.805Z,1534984475.805 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:34:35.805Z,1534984475.805 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:34:35.805Z,1534984475.805 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:34:39.931Z,1534984479.931 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:34:40.092Z,1534984480.092 [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-23T00:34:40.093Z,1534984480.093 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:34:40.094Z,1534984480.094 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:34:40.094Z,1534984480.094 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:36:22.904Z,1534984582.904 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:36:22.904Z,1534984582.904 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 14
2018-08-23T00:36:22.904Z,1534984582.904 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:36:22.951Z,1534984582.951 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:36:23.355Z,1534984583.355 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:36:23.355Z,1534984583.355 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 14
2018-08-23T00:36:23.710Z,1534984583.710 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:36:23.711Z,1534984583.711 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:36:23.711Z,1534984583.711 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:36:36.393Z,1534984596.393 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:36:36.393Z,1534984596.393 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T00:36:36.393Z,1534984596.393 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:36:36.643Z,1534984596.643 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:36:36.797Z,1534984596.797 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:36:36.890Z,1534984596.890 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:36:37.697Z,1534984597.697 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-23T00:36:37.697Z,1534984597.697 [Rowe_600LCM] Hardware Fault, FailCount= 1
2018-08-23T00:36:37.697Z,1534984597.697 [Rowe_600LCM](ERROR): Hardware Fault
2018-08-23T00:36:38.226Z,1534984598.226 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:36:38.226Z,1534984598.226 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T00:36:38.505Z,1534984598.505 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:36:38.505Z,1534984598.505 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:36:38.505Z,1534984598.505 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:36:38.505Z,1534984598.505 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:36:42.747Z,1534984602.747 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:36:42.809Z,1534984602.809 [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-23T00:36:42.810Z,1534984602.810 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:36:42.811Z,1534984602.811 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:36:42.812Z,1534984602.812 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:37:08.939Z,1534984628.939 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-23T00:37:08.939Z,1534984628.939 [NAL9602] Data Fault, FailCount= 4
2018-08-23T00:37:08.939Z,1534984628.939 [NAL9602](ERROR): Data Fault
2018-08-23T00:37:09.015Z,1534984629.015 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-23T00:37:09.339Z,1534984629.339 [NAL9602](INFO): Powering down
2018-08-23T00:37:10.197Z,1534984630.197 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-23T00:37:10.197Z,1534984630.197 [NAL9602] No Fault, FailCount= 4
2018-08-23T00:37:39.471Z,1534984659.471 [NAL9602](INFO): Powering up NAL9602
2018-08-23T00:37:50.663Z,1534984670.663 [NAL9602](INFO): NAL9602 initialized
2018-08-23T00:38:38.569Z,1534984718.569 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:38:38.569Z,1534984718.569 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T00:38:38.569Z,1534984718.569 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:38:38.829Z,1534984718.829 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:38:38.973Z,1534984718.973 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:38:39.070Z,1534984719.070 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:38:40.407Z,1534984720.407 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:38:40.407Z,1534984720.407 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T00:38:40.685Z,1534984720.685 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:38:40.685Z,1534984720.685 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:38:40.685Z,1534984720.685 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:38:40.685Z,1534984720.685 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:38:44.925Z,1534984724.925 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:38:44.984Z,1534984724.984 [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-23T00:38:44.985Z,1534984724.985 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:38:44.986Z,1534984724.986 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:38:44.987Z,1534984724.987 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:39:23.995Z,1534984763.995 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:39:23.995Z,1534984763.995 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 15
2018-08-23T00:39:23.995Z,1534984763.995 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:39:24.035Z,1534984764.035 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:39:24.428Z,1534984764.428 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:39:24.428Z,1534984764.428 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 15
2018-08-23T00:39:24.788Z,1534984764.788 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:39:24.789Z,1534984764.789 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:39:24.789Z,1534984764.789 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:40:40.792Z,1534984840.792 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:40:40.792Z,1534984840.792 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T00:40:40.792Z,1534984840.792 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:40:40.934Z,1534984840.934 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:40:41.197Z,1534984841.197 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:40:41.408Z,1534984841.408 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:40:42.907Z,1534984842.907 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:40:42.907Z,1534984842.907 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T00:40:43.025Z,1534984843.025 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:40:43.025Z,1534984843.025 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:40:43.026Z,1534984843.026 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:40:43.026Z,1534984843.026 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:40:47.148Z,1534984847.148 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:40:47.211Z,1534984847.211 [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-23T00:40:47.218Z,1534984847.218 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:40:47.219Z,1534984847.219 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:40:47.220Z,1534984847.220 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:42:25.125Z,1534984945.125 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:42:25.125Z,1534984945.125 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 16
2018-08-23T00:42:25.125Z,1534984945.125 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:42:25.180Z,1534984945.180 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:42:25.534Z,1534984945.534 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:42:25.534Z,1534984945.534 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 16
2018-08-23T00:42:25.930Z,1534984945.930 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:42:25.931Z,1534984945.931 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:42:25.931Z,1534984945.931 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:42:43.781Z,1534984963.781 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:42:43.781Z,1534984963.781 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T00:42:43.781Z,1534984963.781 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:42:44.123Z,1534984964.123 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:42:44.185Z,1534984964.185 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:42:44.280Z,1534984964.280 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:42:45.722Z,1534984965.722 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:42:45.722Z,1534984965.722 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T00:42:45.897Z,1534984965.897 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:42:45.897Z,1534984965.897 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:42:45.897Z,1534984965.897 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:42:45.898Z,1534984965.898 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:42:50.030Z,1534984970.030 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:42:50.140Z,1534984970.140 [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-23T00:42:50.153Z,1534984970.153 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:42:50.154Z,1534984970.154 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:42:50.154Z,1534984970.154 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:44:45.969Z,1534985085.969 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:44:45.969Z,1534985085.969 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T00:44:45.969Z,1534985085.969 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:44:46.042Z,1534985086.042 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:44:46.043Z,1534985086.043 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T00:44:46.373Z,1534985086.373 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:44:46.556Z,1534985086.556 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:44:47.365Z,1534985087.365 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-23T00:44:47.365Z,1534985087.365 [Rowe_600LCM] Hardware Fault, FailCount= 5
2018-08-23T00:44:47.366Z,1534985087.366 [Rowe_600LCM](ERROR): Hardware Fault
2018-08-23T00:45:26.002Z,1534985126.002 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:45:26.002Z,1534985126.002 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 17
2018-08-23T00:45:26.002Z,1534985126.002 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:45:26.041Z,1534985126.041 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:45:26.412Z,1534985126.412 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:45:26.412Z,1534985126.412 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 17
2018-08-23T00:45:29.485Z,1534985129.485 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:45:29.485Z,1534985129.485 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:45:29.486Z,1534985129.486 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:46:50.767Z,1534985210.767 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.383145 seconds old.
2018-08-23T00:46:51.169Z,1534985211.169 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.784951 seconds old.
2018-08-23T00:46:51.558Z,1534985211.558 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.173730 seconds old.
2018-08-23T00:46:51.956Z,1534985211.956 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.571879 seconds old.
2018-08-23T00:47:51.475Z,1534985271.475 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-23T00:47:51.475Z,1534985271.475 [NAL9602] Data Fault, FailCount= 5
2018-08-23T00:47:51.475Z,1534985271.475 [NAL9602](ERROR): Data Fault
2018-08-23T00:47:51.543Z,1534985271.543 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-23T00:47:51.543Z,1534985271.543 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-08-23T00:47:51.878Z,1534985271.878 [NAL9602](INFO): Powering down
2018-08-23T00:47:51.962Z,1534985271.962 [CBIT](INFO): Critical error at 20180823T004751
2018-08-23T00:47:51.962Z,1534985271.962 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-08-23T00:47:52.327Z,1534985272.327 [MissionManager](INFO): MissionManager is completed.
2018-08-23T00:47:52.328Z,1534985272.328 [MissionManager](INFO): Uninitializing Mission sample
2018-08-23T00:47:52.328Z,1534985272.328 [sample] Stopped
2018-08-23T00:47:52.328Z,1534985272.328 [sample](DEBUG): Aggregate::uninitialize sample
2018-08-23T00:47:52.328Z,1534985272.328 [sample:A.Pitch] Stopped
2018-08-23T00:47:52.328Z,1534985272.328 [sample:SampleAtDepth] Stopped
2018-08-23T00:47:52.328Z,1534985272.328 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleAtDepth:SetZeroRudderInDriftMode] Stopped
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleAtDepth:SetZeroRudderInDriftMode](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SetZeroRudderInDriftMode
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed] Stopped
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleAtDepth:SetZeroRudderInDriftMode:A.SetSpeed](DEBUG): Uninitialize.
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleAtDepth:SetZeroRudderInDriftMode:B.Point] Stopped
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleAtDepth:D.Pitch] Stopped
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleRepeater] Stopped
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleRepeater:Sample] Stopped
2018-08-23T00:47:52.329Z,1534985272.329 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2018-08-23T00:47:52.725Z,1534985272.725 [MissionManager](IMPORTANT): Started mission Default
2018-08-23T00:47:52.725Z,1534985272.725 [Default] Running Loop=1
2018-08-23T00:47:52.726Z,1534985272.726 [Default](DEBUG): Aggregate::initialize Default
2018-08-23T00:47:52.726Z,1534985272.726 [Default:B.GoToSurface] Running Loop=1
2018-08-23T00:47:52.726Z,1534985272.726 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-23T00:47:52.726Z,1534985272.726 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-23T00:47:52.726Z,1534985272.726 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-23T00:47:52.727Z,1534985272.727 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-23T00:47:52.727Z,1534985272.727 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-23T00:47:52.728Z,1534985272.728 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-23T00:47:52.728Z,1534985272.728 [Default:A.Wait] Running Loop=1
2018-08-23T00:47:52.728Z,1534985272.728 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-23T00:48:05.915Z,1534985285.915 [Default:A.Wait](INFO): Done Waiting.
2018-08-23T00:48:05.915Z,1534985285.915 [Default:A.Wait] Stopped
2018-08-23T00:48:05.916Z,1534985285.916 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T00:48:06.323Z,1534985286.323 [Default:CheckIn] Running Loop=1
2018-08-23T00:48:06.323Z,1534985286.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T00:48:06.323Z,1534985286.323 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T00:48:30.210Z,1534985310.210 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:48:30.210Z,1534985310.210 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 18
2018-08-23T00:48:30.210Z,1534985310.210 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:48:30.224Z,1534985310.224 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:48:30.342Z,1534985310.342 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:48:30.342Z,1534985310.342 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 18
2018-08-23T00:48:30.682Z,1534985310.682 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:48:30.682Z,1534985310.682 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:48:30.683Z,1534985310.683 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:49:51.476Z,1534985391.476 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-23T00:49:51.476Z,1534985391.476 [NAL9602] No Fault, FailCount= 5
2018-08-23T00:49:51.809Z,1534985391.809 [NAL9602](INFO): Powering up NAL9602
2018-08-23T00:50:03.009Z,1534985403.009 [NAL9602](INFO): NAL9602 initialized
2018-08-23T00:51:32.119Z,1534985492.119 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:51:32.120Z,1534985492.120 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 19
2018-08-23T00:51:32.120Z,1534985492.120 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:51:32.153Z,1534985492.153 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:51:32.262Z,1534985492.262 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:51:32.262Z,1534985492.262 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 19
2018-08-23T00:51:32.615Z,1534985492.615 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:51:32.616Z,1534985492.616 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:51:32.616Z,1534985492.616 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:53:06.586Z,1534985586.586 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-23T00:48:06.3Z
2018-08-23T00:53:06.586Z,1534985586.586 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T00:53:06.586Z,1534985586.586 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T00:53:12.642Z,1534985592.642 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20180822T235402/Courier0007.lzma
2018-08-23T00:53:13.440Z,1534985593.440 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Courier0007.lzma.bak
2018-08-23T00:53:13.440Z,1534985593.440 [DataOverHttps](INFO): SBD MOMSN=8436705
2018-08-23T00:53:23.605Z,1534985603.605 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T235402/Courier0010.lzma
2018-08-23T00:53:24.403Z,1534985604.403 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Courier0010.lzma.bak
2018-08-23T00:53:24.403Z,1534985604.403 [DataOverHttps](INFO): SBD MOMSN=8436708
2018-08-23T00:53:35.080Z,1534985615.080 [DataOverHttps](INFO): Sending 830 bytes from file Logs/20180822T235402/Express0008.lzma
2018-08-23T00:53:38.315Z,1534985618.315 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Express0008.lzma.bak
2018-08-23T00:53:38.315Z,1534985618.315 [DataOverHttps](INFO): SBD MOMSN=8436710
2018-08-23T00:53:58.717Z,1534985638.717 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180822T235402/Express0011.lzma
2018-08-23T00:54:03.515Z,1534985643.515 [DataOverHttps](INFO): Moved sent file to Logs/20180822T235402/Express0011.lzma.bak
2018-08-23T00:54:03.515Z,1534985643.515 [DataOverHttps](INFO): SBD MOMSN=8436755
2018-08-23T00:54:04.996Z,1534985644.996 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T00:54:04.996Z,1534985644.996 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T00:54:04.996Z,1534985644.996 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T00:54:32.627Z,1534985672.627 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:54:32.628Z,1534985672.628 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 20
2018-08-23T00:54:32.628Z,1534985672.628 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:54:32.642Z,1534985672.642 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:54:33.075Z,1534985673.075 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:54:33.075Z,1534985673.075 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 20
2018-08-23T00:54:33.435Z,1534985673.435 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:54:33.436Z,1534985673.436 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:54:33.436Z,1534985673.436 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:54:46.249Z,1534985686.249 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:54:46.249Z,1534985686.249 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T00:54:46.369Z,1534985686.369 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:54:46.369Z,1534985686.369 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:54:46.369Z,1534985686.369 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:54:46.369Z,1534985686.369 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:54:50.494Z,1534985690.494 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:54:50.557Z,1534985690.557 [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-23T00:54:50.558Z,1534985690.558 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:54:50.559Z,1534985690.559 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:54:50.560Z,1534985690.560 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:56:47.033Z,1534985807.033 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:56:47.033Z,1534985807.033 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T00:56:47.033Z,1534985807.033 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:56:47.338Z,1534985807.338 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:56:47.437Z,1534985807.437 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:56:47.532Z,1534985807.532 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:56:48.903Z,1534985808.903 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:56:48.903Z,1534985808.903 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T00:56:49.149Z,1534985809.149 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:56:49.149Z,1534985809.149 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:56:49.150Z,1534985809.150 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:56:49.150Z,1534985809.150 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:56:53.391Z,1534985813.391 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:56:53.458Z,1534985813.458 [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-23T00:56:53.459Z,1534985813.459 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:56:53.460Z,1534985813.460 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:56:53.461Z,1534985813.461 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:57:33.774Z,1534985853.774 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T00:57:33.774Z,1534985853.774 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 21
2018-08-23T00:57:33.775Z,1534985853.775 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T00:57:33.828Z,1534985853.828 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T00:57:34.213Z,1534985854.213 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T00:57:34.213Z,1534985854.213 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 21
2018-08-23T00:57:34.578Z,1534985854.578 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T00:57:34.578Z,1534985854.578 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T00:57:34.578Z,1534985854.578 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T00:58:49.477Z,1534985929.477 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T00:58:49.478Z,1534985929.478 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T00:58:49.478Z,1534985929.478 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T00:58:49.555Z,1534985929.555 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T00:58:49.882Z,1534985929.882 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T00:58:50.073Z,1534985930.073 [Rowe_600LCM](INFO): Powering down
2018-08-23T00:58:51.537Z,1534985931.537 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T00:58:51.537Z,1534985931.537 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T00:58:51.689Z,1534985931.689 [Rowe_600LCM](INFO): Initializing
2018-08-23T00:58:51.689Z,1534985931.689 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T00:58:51.689Z,1534985931.689 [Rowe_600LCM](INFO): LCM OK
2018-08-23T00:58:51.690Z,1534985931.690 [Rowe_600LCM](INFO): Powering up
2018-08-23T00:58:55.817Z,1534985935.817 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T00:58:55.960Z,1534985935.960 [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-23T00:58:55.961Z,1534985935.961 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T00:58:55.961Z,1534985935.961 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T00:58:55.962Z,1534985935.962 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T00:59:05.132Z,1534985945.132 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T00:59:05.132Z,1534985945.132 [Default:CheckIn:C.Wait] Stopped
2018-08-23T00:59:05.132Z,1534985945.132 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T00:59:05.133Z,1534985945.133 [Default:CheckIn:D] Running Loop=1
2018-08-23T00:59:05.533Z,1534985945.533 [Default:CheckIn:D] Stopped
2018-08-23T00:59:05.533Z,1534985945.533 [Default:CheckIn:E] Running Loop=1
2018-08-23T00:59:05.934Z,1534985945.934 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.213420 min 
2018-08-23T00:59:05.936Z,1534985945.936 [Default:CheckIn:E] Stopped
2018-08-23T00:59:05.936Z,1534985945.936 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T00:59:05.936Z,1534985945.936 [Default:CheckIn] Stopped
2018-08-23T00:59:05.937Z,1534985945.937 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T00:59:05.937Z,1534985945.937 [Default:CheckIn](INFO): Running loop #2
2018-08-23T00:59:05.937Z,1534985945.937 [Default:CheckIn] Running Loop=2
2018-08-23T00:59:05.937Z,1534985945.937 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T00:59:05.937Z,1534985945.937 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T01:00:04.372Z,1534986004.372 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-23T01:00:04.372Z,1534986004.372 [NAL9602] Data Fault, FailCount= 1
2018-08-23T01:00:04.372Z,1534986004.372 [NAL9602](ERROR): Data Fault
2018-08-23T01:00:04.498Z,1534986004.498 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-23T01:00:04.774Z,1534986004.774 [NAL9602](INFO): Powering down
2018-08-23T01:00:05.629Z,1534986005.629 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-23T01:00:05.629Z,1534986005.629 [NAL9602] No Fault, FailCount= 1
2018-08-23T01:00:34.891Z,1534986034.891 [NAL9602](INFO): Powering up NAL9602
2018-08-23T01:00:34.937Z,1534986034.937 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-23T01:00:34.937Z,1534986034.937 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 22
2018-08-23T01:00:34.937Z,1534986034.937 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-23T01:00:34.951Z,1534986034.951 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-23T01:00:35.347Z,1534986035.347 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-23T01:00:35.348Z,1534986035.348 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 22
2018-08-23T01:00:35.726Z,1534986035.726 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T01:00:35.727Z,1534986035.727 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T01:00:35.727Z,1534986035.727 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T01:00:46.087Z,1534986046.087 [NAL9602](INFO): NAL9602 initialized
2018-08-23T01:00:52.417Z,1534986052.417 [Rowe_600LCM](FAULT): Did not receive valid