2019-07-17T18:38:00.177Z,1563388680.177 [Supervisor](DEBUG): Initializing supervisor.
2019-07-17T18:38:00.180Z,1563388680.180 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-07-17T18:38:00.181Z,1563388680.181 [SyncHandler](INFO): Protected caller Thread ID is 6860
2019-07-17T18:38:00.181Z,1563388680.181 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-07-17T18:38:00.182Z,1563388680.182 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-07-17T18:38:00.183Z,1563388680.183 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6861
2019-07-17T18:38:00.186Z,1563388680.186 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-07-17T18:38:00.197Z,1563388680.197 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-07-17T18:38:00.198Z,1563388680.198 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-07-17T18:38:00.199Z,1563388680.199 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6862
2019-07-17T18:38:00.200Z,1563388680.200 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-07-17T18:38:00.201Z,1563388680.201 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-07-17T18:38:00.201Z,1563388680.201 [logger ThreadHandler](INFO): Protected caller Thread ID is 6863
2019-07-17T18:38:00.203Z,1563388680.203 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-07-17T18:38:00.203Z,1563388680.203 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-07-17T18:38:00.205Z,1563388680.205 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-07-17T18:38:00.369Z,1563388680.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-07-17T18:38:00.370Z,1563388680.370 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-07-17T18:38:00.570Z,1563388680.570 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-07-17T18:38:00.571Z,1563388680.571 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-07-17T18:38:00.708Z,1563388680.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-07-17T18:38:00.708Z,1563388680.708 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-07-17T18:38:01.264Z,1563388681.264 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-07-17T18:38:01.264Z,1563388681.264 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-07-17T18:38:01.702Z,1563388681.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-07-17T18:38:01.703Z,1563388681.703 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-07-17T18:38:02.173Z,1563388682.173 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-07-17T18:38:02.174Z,1563388682.174 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-07-17T18:38:02.477Z,1563388682.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-07-17T18:38:02.477Z,1563388682.477 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-07-17T18:38:03.596Z,1563388683.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-07-17T18:38:03.597Z,1563388683.597 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-07-17T18:38:04.407Z,1563388684.407 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-07-17T18:38:04.408Z,1563388684.408 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-07-17T18:38:05.062Z,1563388685.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-07-17T18:38:05.063Z,1563388685.063 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-07-17T18:38:05.648Z,1563388685.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-07-17T18:38:05.648Z,1563388685.648 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-07-17T18:38:06.173Z,1563388686.173 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-07-17T18:38:06.646Z,1563388686.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-07-17T18:38:06.647Z,1563388686.647 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-07-17T18:38:06.882Z,1563388686.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-07-17T18:38:06.883Z,1563388686.883 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-07-17T18:38:07.096Z,1563388687.096 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-07-17T18:38:07.098Z,1563388687.098 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-07-17T18:38:07.099Z,1563388687.099 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-07-17T18:38:07.186Z,1563388687.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-07-17T18:38:07.414Z,1563388687.414 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-07-17T18:38:07.415Z,1563388687.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-07-17T18:38:07.511Z,1563388687.511 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-07-17T18:38:07.677Z,1563388687.677 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-07-17T18:38:07.880Z,1563388687.880 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-07-17T18:38:07.967Z,1563388687.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-07-17T18:38:08.067Z,1563388688.067 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-07-17T18:38:08.162Z,1563388688.162 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-07-17T18:38:08.364Z,1563388688.364 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-07-17T18:38:08.807Z,1563388688.807 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-07-17T18:38:09.274Z,1563388689.274 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-07-17T18:38:09.295Z,1563388689.295 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-07-17T18:38:09.415Z,1563388689.415 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-07-17T18:38:09.415Z,1563388689.415 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-07-17T18:38:09.562Z,1563388689.562 [BuoyancyServo] Loaded
2019-07-17T18:38:09.562Z,1563388689.562 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-07-17T18:38:09.577Z,1563388689.577 [ElevatorServo] Loaded
2019-07-17T18:38:09.577Z,1563388689.577 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-07-17T18:38:09.591Z,1563388689.591 [MassServo] Loaded
2019-07-17T18:38:09.591Z,1563388689.591 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-07-17T18:38:09.606Z,1563388689.606 [RudderServo] Loaded
2019-07-17T18:38:09.606Z,1563388689.606 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-07-17T18:38:09.620Z,1563388689.620 [ThrusterServo] Loaded
2019-07-17T18:38:09.620Z,1563388689.620 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-07-17T18:38:09.621Z,1563388689.621 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-07-17T18:38:09.621Z,1563388689.621 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-07-17T18:38:09.775Z,1563388689.775 [SBIT](DEBUG): Construct Startup Built In Test.
2019-07-17T18:38:09.803Z,1563388689.803 [SBIT] Loaded
2019-07-17T18:38:09.803Z,1563388689.803 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-07-17T18:38:09.804Z,1563388689.804 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-07-17T18:38:09.830Z,1563388689.830 [IBIT] Loaded
2019-07-17T18:38:09.831Z,1563388689.831 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-07-17T18:38:09.834Z,1563388689.834 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-07-17T18:38:10.208Z,1563388690.208 [CBIT] Loaded
2019-07-17T18:38:10.209Z,1563388690.209 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-07-17T18:38:10.209Z,1563388690.209 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-07-17T18:38:10.210Z,1563388690.210 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-07-17T18:38:10.462Z,1563388690.462 [Aanderaa_O2] Loaded
2019-07-17T18:38:10.462Z,1563388690.462 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-07-17T18:38:10.472Z,1563388690.472 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-07-17T18:38:10.477Z,1563388690.477 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-07-17T18:38:10.479Z,1563388690.479 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-07-17T18:38:10.484Z,1563388690.484 [CTD_Seabird](INFO): created writer for : depth
2019-07-17T18:38:10.484Z,1563388690.484 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-07-17T18:38:10.489Z,1563388690.489 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-07-17T18:38:10.490Z,1563388690.490 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-07-17T18:38:10.495Z,1563388690.495 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-07-17T18:38:10.495Z,1563388690.495 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-07-17T18:38:10.501Z,1563388690.500 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-07-17T18:38:10.501Z,1563388690.501 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-07-17T18:38:10.506Z,1563388690.506 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-07-17T18:38:10.507Z,1563388690.507 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-07-17T18:38:10.512Z,1563388690.512 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-07-17T18:38:10.537Z,1563388690.537 [CTD_Seabird] Loaded
2019-07-17T18:38:10.538Z,1563388690.538 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-07-17T18:38:10.539Z,1563388690.539 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4066A4E0
2019-07-17T18:38:10.539Z,1563388690.539 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6942
2019-07-17T18:38:10.568Z,1563388690.568 [ESPComponent] Loaded
2019-07-17T18:38:10.568Z,1563388690.568 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-07-17T18:38:10.582Z,1563388690.582 [PAR_Licor] Loaded
2019-07-17T18:38:10.582Z,1563388690.582 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-07-17T18:38:10.628Z,1563388690.628 [WetLabsBB2FL] Loaded
2019-07-17T18:38:10.628Z,1563388690.628 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-07-17T18:38:10.629Z,1563388690.629 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4069A4E0
2019-07-17T18:38:10.630Z,1563388690.630 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6943
2019-07-17T18:38:10.630Z,1563388690.630 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-07-17T18:38:10.631Z,1563388690.631 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-07-17T18:38:10.685Z,1563388690.685 [DepthRateCalculator] Loaded
2019-07-17T18:38:10.685Z,1563388690.685 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-07-17T18:38:10.691Z,1563388690.691 [PitchRateCalculator] Loaded
2019-07-17T18:38:10.691Z,1563388690.691 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-07-17T18:38:10.706Z,1563388690.706 [SpeedCalculator] Loaded
2019-07-17T18:38:10.706Z,1563388690.706 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-07-17T18:38:10.727Z,1563388690.727 [TempGradientCalculator] Loaded
2019-07-17T18:38:10.727Z,1563388690.727 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-07-17T18:38:10.732Z,1563388690.732 [YawRateCalculator] Loaded
2019-07-17T18:38:10.733Z,1563388690.733 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-07-17T18:38:10.764Z,1563388690.764 [ElevatorOffsetCalculator] Loaded
2019-07-17T18:38:10.764Z,1563388690.764 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-07-17T18:38:10.765Z,1563388690.765 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-07-17T18:38:10.765Z,1563388690.765 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-07-17T18:38:10.841Z,1563388690.841 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-07-17T18:38:10.841Z,1563388690.841 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-07-17T18:38:10.958Z,1563388690.958 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-07-17T18:38:10.958Z,1563388690.958 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-07-17T18:38:10.979Z,1563388690.979 [NavChart] Loaded
2019-07-17T18:38:10.979Z,1563388690.979 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-07-17T18:38:10.983Z,1563388690.983 [UniversalFixResidualReporter] Loaded
2019-07-17T18:38:10.984Z,1563388690.984 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-07-17T18:38:10.984Z,1563388690.984 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-07-17T18:38:10.985Z,1563388690.985 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-07-17T18:38:11.446Z,1563388691.446 [AHRS_M2] Loaded
2019-07-17T18:38:11.446Z,1563388691.446 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-07-17T18:38:11.519Z,1563388691.519 [DataOverHttps] Loaded
2019-07-17T18:38:11.519Z,1563388691.519 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-07-17T18:38:11.520Z,1563388691.520 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409734E0
2019-07-17T18:38:11.521Z,1563388691.521 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6944
2019-07-17T18:38:11.533Z,1563388691.533 [Depth_Keller] Loaded
2019-07-17T18:38:11.534Z,1563388691.534 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-07-17T18:38:11.660Z,1563388691.660 [DVL_micro] Loaded
2019-07-17T18:38:11.661Z,1563388691.661 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-07-17T18:38:11.748Z,1563388691.748 [NAL9602] Loaded
2019-07-17T18:38:11.748Z,1563388691.748 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-07-17T18:38:11.753Z,1563388691.753 [Onboard] Loaded
2019-07-17T18:38:11.753Z,1563388691.753 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-07-17T18:38:11.877Z,1563388691.877 [DAT] Loaded
2019-07-17T18:38:11.878Z,1563388691.878 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-07-17T18:38:13.135Z,1563388693.135 [BPC1] Loaded
2019-07-17T18:38:13.136Z,1563388693.136 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-07-17T18:38:13.136Z,1563388693.136 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-07-17T18:38:13.137Z,1563388693.137 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-07-17T18:38:13.246Z,1563388693.246 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-07-17T18:38:13.247Z,1563388693.247 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-07-17T18:38:13.334Z,1563388693.334 [VerticalControl](DEBUG): Construct VerticalControl.
2019-07-17T18:38:13.414Z,1563388693.414 [VerticalControl] Loaded
2019-07-17T18:38:13.415Z,1563388693.415 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-07-17T18:38:13.415Z,1563388693.415 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-07-17T18:38:13.471Z,1563388693.471 [HorizontalControl] Loaded
2019-07-17T18:38:13.471Z,1563388693.471 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-07-17T18:38:13.472Z,1563388693.472 [SpeedControl](DEBUG): Construct SpeedControl.
2019-07-17T18:38:13.473Z,1563388693.473 [SpeedControl] Loaded
2019-07-17T18:38:13.474Z,1563388693.474 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-07-17T18:38:13.474Z,1563388693.474 [LoopControl](DEBUG): Construct LoopControl.
2019-07-17T18:38:13.475Z,1563388693.475 [LoopControl] Loaded
2019-07-17T18:38:13.475Z,1563388693.475 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-07-17T18:38:13.475Z,1563388693.475 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-07-17T18:38:13.476Z,1563388693.476 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-07-17T18:38:13.533Z,1563388693.533 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-07-17T18:38:13.533Z,1563388693.533 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-07-17T18:38:14.028Z,1563388694.028 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-07-17T18:38:14.032Z,1563388694.032 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-07-17T18:38:14.033Z,1563388694.033 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-07-17T18:38:14.039Z,1563388694.039 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-07-17T18:38:14.040Z,1563388694.040 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AAE4E0
2019-07-17T18:38:14.041Z,1563388694.041 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6945
2019-07-17T18:38:14.045Z,1563388694.045 [Supervisor](INFO): Main Thread ID is 4171
2019-07-17T18:38:14.046Z,1563388694.046 [Supervisor](DEBUG): Running supervisor.
2019-07-17T18:38:14.046Z,1563388694.046 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6946
2019-07-17T18:38:14.049Z,1563388694.049 [controlThread ThreadHandler](INFO): Handler Thread ID is 6947
2019-07-17T18:38:14.049Z,1563388694.049 [controlThread](DEBUG): Initializing ControlThread
2019-07-17T18:38:14.051Z,1563388694.051 [SBIT](INFO): Initialize SBIT Component.
2019-07-17T18:38:14.051Z,1563388694.051 [SBIT](IMPORTANT): git: 2019-07-16
2019-07-17T18:38:14.051Z,1563388694.051 [SBIT](INFO): git hash: 5dde538a58d6fd4f55501de4ce986b4d4d3b120b
2019-07-17T18:38:14.052Z,1563388694.052 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-07-17T18:38:14.053Z,1563388694.053 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-07-17T18:38:14.054Z,1563388694.054 [SBIT](INFO): Beginning SBIT in 75.000000 seconds.
2019-07-17T18:38:14.055Z,1563388694.055 [IBIT](INFO): Initialize IBIT Component.
2019-07-17T18:38:14.055Z,1563388694.055 [CBIT](DEBUG): Initialize CBIT Component.
2019-07-17T18:38:14.056Z,1563388694.056 [logger ThreadHandler](INFO): Handler Thread ID is 6948
2019-07-17T18:38:14.069Z,1563388694.069 [CBIT](DEBUG): Initialized mux pins.
2019-07-17T18:38:14.069Z,1563388694.069 [CBIT](DEBUG): Initializing the watchdog timer.
2019-07-17T18:38:14.081Z,1563388694.081 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6949
2019-07-17T18:38:14.082Z,1563388694.082 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-07-17T18:38:14.085Z,1563388694.085 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-07-17T18:38:14.087Z,1563388694.087 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6951
2019-07-17T18:38:14.088Z,1563388694.088 [WetLabsBB2FL](INFO): Powering down
2019-07-17T18:38:14.093Z,1563388694.093 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-07-17T18:38:14.093Z,1563388694.093 [CBIT](DEBUG): Initializing heartbeat.
2019-07-17T18:38:14.117Z,1563388694.117 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6952
2019-07-17T18:38:14.118Z,1563388694.118 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-07-17T18:38:14.129Z,1563388694.129 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6953
2019-07-17T18:38:14.138Z,1563388694.138 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-07-17T18:38:14.138Z,1563388694.138 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-07-17T18:38:14.139Z,1563388694.139 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-07-17T18:38:14.139Z,1563388694.139 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-07-17T18:38:14.139Z,1563388694.139 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-07-17T18:38:14.139Z,1563388694.139 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-07-17T18:38:14.139Z,1563388694.139 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-07-17T18:38:14.139Z,1563388694.139 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-07-17T18:38:14.140Z,1563388694.140 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-07-17T18:38:14.140Z,1563388694.140 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-07-17T18:38:14.140Z,1563388694.140 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-07-17T18:38:14.140Z,1563388694.140 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-07-17T18:38:14.140Z,1563388694.140 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-07-17T18:38:14.141Z,1563388694.141 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-07-17T18:38:14.141Z,1563388694.141 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-07-17T18:38:14.141Z,1563388694.141 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-07-17T18:38:14.165Z,1563388694.165 [CBIT](DEBUG): Deactivating GF circuits.
2019-07-17T18:38:14.165Z,1563388694.165 [CBIT](DEBUG): Deactivating emergency mode.
2019-07-17T18:38:14.201Z,1563388694.201 [CBIT](DEBUG): Backplane powered.
2019-07-17T18:38:14.205Z,1563388694.205 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-07-17T18:38:14.205Z,1563388694.205 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-07-17T18:38:14.206Z,1563388694.206 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-07-17T18:38:14.206Z,1563388694.206 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-07-17T18:38:14.207Z,1563388694.207 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-07-17T18:38:14.207Z,1563388694.207 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-07-17T18:38:14.208Z,1563388694.208 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-07-17T18:38:14.208Z,1563388694.208 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-07-17T18:38:14.219Z,1563388694.219 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-07-17T18:38:14.221Z,1563388694.221 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-07-17T18:38:14.221Z,1563388694.221 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-07-17T18:38:14.222Z,1563388694.222 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-07-17T18:38:14.223Z,1563388694.223 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-07-17T18:38:14.247Z,1563388694.247 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-17T18:38:14.287Z,1563388694.287 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2019-07-17T18:38:14.287Z,1563388694.287 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-07-17T18:38:14.362Z,1563388694.362 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-07-17T18:38:14.363Z,1563388694.363 [Default:A.Wait](DEBUG): Construct Wait.
2019-07-17T18:38:14.365Z,1563388694.365 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-17T18:38:14.400Z,1563388694.400 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-07-17T18:38:14.418Z,1563388694.418 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-07-17T18:38:14.424Z,1563388694.424 [Default:E.Execute](DEBUG): Construct Execute.
2019-07-17T18:38:14.444Z,1563388694.444 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-07-17T18:38:14.449Z,1563388694.449 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-07-17T18:38:14.488Z,1563388694.488 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-07-17T18:38:14.649Z,1563388694.649 [DVL_micro](INFO): Initializing
2019-07-17T18:38:14.675Z,1563388694.675 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-07-17T18:38:14.675Z,1563388694.675 [DAT](INFO): Powering up
2019-07-17T18:38:14.675Z,1563388694.675 [DAT](DEBUG): Initializing DAT.
2019-07-17T18:38:14.743Z,1563388694.743 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-07-17T18:38:14.745Z,1563388694.745 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-07-17T18:38:14.773Z,1563388694.773 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-07-17T18:38:14.775Z,1563388694.775 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-07-17T18:38:14.785Z,1563388694.785 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-07-17T18:38:14.786Z,1563388694.786 [MassServo](DEBUG): Initializing EZServoServo.
2019-07-17T18:38:14.797Z,1563388694.797 [MassServo](DEBUG): Initializing MassServo.
2019-07-17T18:38:14.798Z,1563388694.798 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-17T18:38:14.809Z,1563388694.809 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-17T18:38:14.810Z,1563388694.810 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-07-17T18:38:14.821Z,1563388694.821 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-07-17T18:38:15.621Z,1563388695.621 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-07-17T18:38:15.621Z,1563388695.621 [RudderServo](FAULT): Rudder failed to initialize
2019-07-17T18:38:15.621Z,1563388695.621 [RudderServo] Communications Fault, FailCount= 1
2019-07-17T18:38:15.621Z,1563388695.621 [RudderServo](ERROR): Communications Fault
2019-07-17T18:38:15.804Z,1563388695.804 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-07-17T18:38:15.994Z,1563388695.994 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-17T18:38:15.994Z,1563388695.994 [RudderServo](INFO): Powering down
2019-07-17T18:38:16.233Z,1563388696.233 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:16.234Z,1563388696.234 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -Q29988 -à65769 Á92301 Œ49308 5.16 -2.45 19.9 0.2 18.1 0.005 35.0 1489 3247
2019-07-17T18:38:16.683Z,1563388696.683 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-17T18:38:16.802Z,1563388696.802 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-17T18:38:16.806Z,1563388696.806 [CBIT](INFO): Clearing failed state for component RudderServo
2019-07-17T18:38:16.806Z,1563388696.806 [RudderServo] No Fault, FailCount= 1
2019-07-17T18:38:17.043Z,1563388697.043 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:17.044Z,1563388697.044 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.18 -2.53 20.0 0.2 18.2 0.005 35.0 1489 3238
2019-07-17T18:38:17.949Z,1563388697.949 [Aanderaa_O2](INFO): Powering down
2019-07-17T18:38:18.090Z,1563388698.090 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:18.090Z,1563388698.090 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.18 -2.44 20.1 0.2 18.1 0.005 35.0 1489 3234
2019-07-17T18:38:18.679Z,1563388698.679 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:18.679Z,1563388698.679 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.20 -2.47 20.2 0.2 18.2 0.005 35.0 1489 3242
2019-07-17T18:38:19.499Z,1563388699.499 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:19.499Z,1563388699.499 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.12 -2.51 20.2 0.2 18.1 0.005 35.0 1489 3247
2019-07-17T18:38:20.303Z,1563388700.303 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:20.303Z,1563388700.303 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.15 -2.53 20.4 0.2 18.2 0.005 35.0 1489 3247
2019-07-17T18:38:21.119Z,1563388701.119 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:21.119Z,1563388701.119 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.24 -2.46 20.6 0.2 18.1 0.005 35.0 1489 3240
2019-07-17T18:38:21.923Z,1563388701.923 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:21.923Z,1563388701.923 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.18 -2.56 20.6 0.2 18.1 0.005 35.0 1489 3238
2019-07-17T18:38:22.725Z,1563388702.725 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:22.726Z,1563388702.726 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.19 -2.51 20.7 0.2 18.2 0.005 35.0 1489 3234
2019-07-17T18:38:23.526Z,1563388703.526 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:23.527Z,1563388703.527 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.15 -2.53 20.7 0.2 18.1 0.005 35.0 1489 3247
2019-07-17T18:38:24.322Z,1563388704.322 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:24.323Z,1563388704.323 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.22 -2.51 20.9 0.2 18.1 0.005 35.0 1489 3239
2019-07-17T18:38:25.146Z,1563388705.146 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:25.147Z,1563388705.147 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.25 -2.48 20.9 0.2 18.1 0.005 35.0 1489 3240
2019-07-17T18:38:25.927Z,1563388705.927 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:25.927Z,1563388705.927 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.18 -2.59 21.0 0.2 18.2 0.005 35.0 1489 3245
2019-07-17T18:38:26.734Z,1563388706.734 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:26.735Z,1563388706.735 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.23 -2.48 21.1 0.2 18.2 0.005 35.0 1489 3236
2019-07-17T18:38:27.545Z,1563388707.545 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:27.546Z,1563388707.546 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.22 -2.53 21.2 0.2 18.2 0.005 35.0 1489 3244
2019-07-17T18:38:28.351Z,1563388708.351 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:28.351Z,1563388708.351 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.23 -2.53 21.2 0.2 18.1 0.005 35.0 1489 3246
2019-07-17T18:38:29.159Z,1563388709.159 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:29.159Z,1563388709.159 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.18 -2.52 21.3 0.2 18.1 0.005 35.0 1489 3238
2019-07-17T18:38:29.963Z,1563388709.963 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:29.963Z,1563388709.963 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.26 -2.50 21.4 0.2 18.1 0.005 35.0 1489 3246
2019-07-17T18:38:29.981Z,1563388709.981 [DAT](INFO): setting local address to 3
2019-07-17T18:38:30.380Z,1563388710.380 [DAT](INFO): set local address to 3
2019-07-17T18:38:30.774Z,1563388710.774 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:30.775Z,1563388710.775 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.25 -2.46 21.4 0.2 18.1 0.005 35.0 1489 3242
2019-07-17T18:38:31.579Z,1563388711.579 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:31.579Z,1563388711.579 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.13 -2.59 21.4 0.2 18.1 0.005 35.0 1489 3233
2019-07-17T18:38:32.391Z,1563388712.391 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:32.391Z,1563388712.391 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.29 -2.54 21.6 0.2 18.2 0.005 35.0 1489 3236
2019-07-17T18:38:33.199Z,1563388713.199 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:33.199Z,1563388713.199 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.20 -2.65 21.6 0.2 18.1 0.005 35.0 1489 3244
2019-07-17T18:38:34.003Z,1563388714.003 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:34.003Z,1563388714.003 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.18 -2.62 21.7 0.2 18.1 0.005 35.0 1489 3233
2019-07-17T18:38:34.815Z,1563388714.815 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:34.815Z,1563388714.815 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.26 -2.58 21.8 0.2 18.1 0.005 35.0 1489 3242
2019-07-17T18:38:35.658Z,1563388715.658 [DVL_micro](ERROR): only read 29 of 46 data items
2019-07-17T18:38:35.659Z,1563388715.659 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 {60826 964652 -÷91228 -‚28892 -Q29988 -à65769 Á92301 Œ49308 5.23 -2.59 21.9 0.2 18.1 0.005 35.0 1489 3247
2019-07-17T18:38:42.121Z,1563388722.121 [NAL9602](INFO): Powering up NAL9602
2019-07-17T18:38:44.821Z,1563388724.821 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2019-07-17T18:38:52.987Z,1563388732.987 [NAL9602](INFO): NAL9602 initialized
2019-07-17T18:38:53.809Z,1563388733.809 [NAL9602](DEBUG): Fix Requested
2019-07-17T18:39:29.827Z,1563388769.827 [SBIT](IMPORTANT): Beginning Startup BIT
2019-07-17T18:39:29.835Z,1563388769.835 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-17T18:39:31.390Z,1563388771.390 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:39:31.391Z,1563388771.391 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:39:40.837Z,1563388780.837 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005336
CHAN A1 (24V): -0.013411
CHAN A2 (12V): -0.005932
CHAN A3 (5V): -0.007280
CHAN B0 (3.3V): -0.003773
CHAN B1 (3.15aV): -0.001923
CHAN B2 (3.15bV): -0.002595
CHAN B3 (GND): -0.001934
OPEN: 0.012180
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-17T18:40:22.062Z,1563388822.062 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:40:22.062Z,1563388822.062 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:40:23.351Z,1563388823.351 [SBIT](FAULT): Mass: EXPECTED:-0.014000 ACTUAL:-0.013004
2019-07-17T18:40:23.351Z,1563388823.351 [SBIT](FAULT): Control surface position failure.
2019-07-17T18:40:23.716Z,1563388823.716 [SBIT](CRITICAL): SBIT FAILED
2019-07-17T18:40:23.736Z,1563388823.736 [CommandLine](FAULT): Scheduling is paused
2019-07-17T18:40:23.736Z,1563388823.736 [CBIT](INFO): Critical error at 20190717T184023
2019-07-17T18:40:23.737Z,1563388823.737 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-07-17T18:40:23.774Z,1563388823.774 [CommandLine](IMPORTANT): got command configSet list
2019-07-17T18:40:23.774Z,1563388823.774 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-17T18:40:23.775Z,1563388823.775 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=1 bool;

2019-07-17T18:40:23.775Z,1563388823.775 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2019-07-17T18:40:23.775Z,1563388823.775 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-07-17T18:40:23.775Z,1563388823.775 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=6 hour;

2019-07-17T18:40:23.775Z,1563388823.775 [CommandLine](IMPORTANT): BR_Ping1D.verbosity=1 count;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): CBIT.abortDepth=300 meter;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): CBIT.stopDepth=295 meter;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=1 bool;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): Express linearApproximation DAT.range 20.000000 meter;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2019-07-17T18:40:23.776Z,1563388823.776 [CommandLine](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): PAR_Licor.adcCal=8.765e-06 microampere_per_count;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): PAR_Licor.darkCount=0 count;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): PAR_Licor.multiplier=190.3 micromole_per_second_per_square_meter_per_microampere;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): PNI_TCM.loadAtStartup=0 bool;

2019-07-17T18:40:23.777Z,1563388823.777 [CommandLine](IMPORTANT): Radio_Surface.loadAtStartup=0 bool;

2019-07-17T18:40:23.778Z,1563388823.778 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2019-07-17T18:40:23.778Z,1563388823.778 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=90 cubic_centimeter;

2019-07-17T18:40:23.778Z,1563388823.778 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1.4 centimeter;

2019-07-17T18:40:24.114Z,1563388824.114 [MissionManager](IMPORTANT): Started mission Startup
2019-07-17T18:40:24.114Z,1563388824.114 [Startup] Running Loop=1
2019-07-17T18:40:24.114Z,1563388824.114 [Startup](DEBUG): Aggregate::initialize Startup
2019-07-17T18:40:24.114Z,1563388824.114 [Startup:A.GoToSurface] Running Loop=1
2019-07-17T18:40:24.115Z,1563388824.115 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-17T18:40:24.115Z,1563388824.115 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-17T18:40:24.116Z,1563388824.116 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-17T18:40:24.116Z,1563388824.116 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-17T18:40:24.116Z,1563388824.116 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-17T18:40:24.117Z,1563388824.117 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-17T18:40:24.118Z,1563388824.118 [Startup:StartupSatComms] Running Loop=1
2019-07-17T18:40:24.118Z,1563388824.118 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-07-17T18:40:24.119Z,1563388824.119 [Startup:StartupSatComms:A] Running Loop=1
2019-07-17T18:40:24.511Z,1563388824.511 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-07-17T18:41:05.690Z,1563388865.690 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:41:05.690Z,1563388865.690 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:41:14.210Z,1563388874.210 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-07-17T18:41:14.210Z,1563388874.210 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-17T18:41:14.233Z,1563388874.233 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-17T18:41:14.614Z,1563388874.614 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-17T18:41:14.614Z,1563388874.614 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-07-17T18:41:23.476Z,1563388883.476 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:41:23.477Z,1563388883.477 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:41:24.311Z,1563388884.311 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-17T18:40:24.1Z
2019-07-17T18:41:24.311Z,1563388884.311 [Startup:StartupSatComms:A] Stopped
2019-07-17T18:41:24.311Z,1563388884.311 [Startup:StartupSatComms:B] Running Loop=1
2019-07-17T18:41:24.750Z,1563388884.750 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-17T18:42:06.705Z,1563388926.705 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:42:06.705Z,1563388926.705 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:42:23.685Z,1563388943.685 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:42:23.686Z,1563388943.686 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:42:24.546Z,1563388944.546 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-17T18:41:24.3Z
2019-07-17T18:42:24.546Z,1563388944.546 [Startup:StartupSatComms:B] Stopped
2019-07-17T18:42:24.546Z,1563388944.546 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-07-17T18:42:24.547Z,1563388944.547 [Startup:StartupSatComms] Stopped
2019-07-17T18:42:24.547Z,1563388944.547 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-07-17T18:42:24.547Z,1563388944.547 [Startup](INFO): Completed Startup
2019-07-17T18:42:24.548Z,1563388944.548 [MissionManager](INFO): Startup is completed.
2019-07-17T18:42:24.548Z,1563388944.548 [MissionManager](INFO): Uninitializing Mission Startup
2019-07-17T18:42:24.548Z,1563388944.548 [Startup] Stopped
2019-07-17T18:42:24.548Z,1563388944.548 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-07-17T18:42:24.548Z,1563388944.548 [Startup:A.GoToSurface] Stopped
2019-07-17T18:42:24.548Z,1563388944.548 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-17T18:42:24.898Z,1563388944.898 [MissionManager](IMPORTANT): Started mission Default
2019-07-17T18:42:24.898Z,1563388944.898 [Default] Running Loop=1
2019-07-17T18:42:24.899Z,1563388944.899 [Default](DEBUG): Aggregate::initialize Default
2019-07-17T18:42:24.899Z,1563388944.899 [Default:B.GoToSurface] Running Loop=1
2019-07-17T18:42:24.899Z,1563388944.899 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-17T18:42:24.899Z,1563388944.899 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-17T18:42:24.899Z,1563388944.899 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-17T18:42:24.900Z,1563388944.900 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-17T18:42:24.900Z,1563388944.900 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-17T18:42:24.900Z,1563388944.900 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-17T18:42:24.901Z,1563388944.901 [Default:A.Wait] Running Loop=1
2019-07-17T18:42:24.901Z,1563388944.901 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-17T18:42:38.259Z,1563388958.259 [Default:A.Wait](INFO): Done Waiting.
2019-07-17T18:42:38.259Z,1563388958.259 [Default:A.Wait] Stopped
2019-07-17T18:42:38.259Z,1563388958.259 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-17T18:42:38.634Z,1563388958.634 [Default:CheckIn] Running Loop=1
2019-07-17T18:42:38.635Z,1563388958.635 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-17T18:42:38.635Z,1563388958.635 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-17T18:42:39.052Z,1563388959.052 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-07-17T18:42:41.065Z,1563388961.065 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:42:41.065Z,1563388961.065 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:42:49.114Z,1563388969.114 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:42:49.114Z,1563388969.114 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:43:06.090Z,1563388986.090 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:43:06.090Z,1563388986.090 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:43:23.469Z,1563389003.469 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:43:23.469Z,1563389003.469 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:43:28.317Z,1563389008.317 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:43:28.318Z,1563389008.318 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:43:44.870Z,1563389024.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:43:44.870Z,1563389024.870 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:43:59.418Z,1563389039.418 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:43:59.418Z,1563389039.418 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:43:59.837Z,1563389039.837 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-17T18:44:00.657Z,1563389040.657 [NAL9602](DEBUG): Fix Requested
2019-07-17T18:44:01.038Z,1563389041.038 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171034.00,A,3648.16244,N,12147.28533,W,0.292,0.00,170719,,,A*7E
2019-07-17T18:44:01.042Z,1563389041.042 [NAL9602](INFO): GPS fix at 20190717T171034: (36.802707, -121.788089)
2019-07-17T18:44:01.095Z,1563389041.095 [Default:CheckIn:Read_GPS] Stopped
2019-07-17T18:44:01.095Z,1563389041.095 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-17T18:44:01.586Z,1563389041.586 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-17T18:44:13.134Z,1563389053.134 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-17T18:44:13.134Z,1563389053.134 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.3 0.2 10.2 493.7 -108.1 -219.9 37.7 0 -149 0 575 0 -966.3 0 0 0 0 0 0 0 -966 0 0 0 0 0 0 5.25 -10.14 359.3 0.2 18.2 0.005 35.0 1489 79
2019-07-17T18:44:14.810Z,1563389054.810 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:44:14.810Z,1563389054.810 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:44:33.231Z,1563389073.231 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:44:33.232Z,1563389073.232 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:44:49.513Z,1563389089.513 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:44:49.515Z,1563389089.515 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:44:57.394Z,1563389097.394 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-17T18:44:57.395Z,1563389097.395 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.4 0.2 10.1 541.0 -636.2 -64.3 -367.9 0 -280 0 -658 0 1 0 2 807.9 -358.1 -142.2 1 778.2 -441.2 -28.7 1 0 504 0 0 0 0 0 0 520 353.5 0.2 18.1 0.005 35.0 1489 98
2019-07-17T18:45:24.905Z,1563389124.905 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:45:24.905Z,1563389124.905 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:45:52.605Z,1563389152.605 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:45:52.605Z,1563389152.605 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:45:59.214Z,1563389159.214 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-17T18:45:59.215Z,1563389159.215 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-17T18:45:59.215Z,1563389159.215 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-07-17T18:45:59.218Z,1563389159.218 [BPC1](INFO): Received data from all battery sticks.
2019-07-17T18:46:07.546Z,1563389167.546 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:46:07.546Z,1563389167.546 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:46:28.171Z,1563389188.171 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:46:28.171Z,1563389188.171 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:46:50.102Z,1563389210.102 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:46:50.102Z,1563389210.102 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:46:59.989Z,1563389219.989 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-17T18:46:59.989Z,1563389219.989 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.4 0.2 10.2 44.4 -103.2 18.5 0 518 0 533 0 1 0 2 850.3 -484.3 28.3 1 667.8 -703.1 13-20 0 0 0 0 0 0 5.20 -10.24 344.0 0.2 18.2 0.005 35.0 1489 91
2019-07-17T18:47:24.199Z,1563389244.199 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:47:24.199Z,1563389244.199 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:47:54.419Z,1563389274.419 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:47:54.419Z,1563389274.419 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:48:08.409Z,1563389288.409 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-17T18:48:08.409Z,1563389288.409 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 0.2 9.4 0.2 0 546.9 -16.4 -1.2 0 0 693 0 196 0 1 0 2 0 663.3 0 0 0 0 0 0 0 663 0 0 0 0 0 0 5.28 -10.20.2 18.2 0.005 35.0 1489 82
2019-07-17T18:49:13.067Z,1563389353.067 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:49:13.067Z,1563389353.067 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:49:31.624Z,1563389371.624 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-17T18:49:31.624Z,1563389371.624 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 0 1 0.2 9.6 0 10.6 665.2 -35.1 0 -753.3 0 822 -357 -507 0 1 2 2 2827.8 958.5 -425.2 1 2270.6 1982.9 -97.9 1 -4269 2 -1056 1485 169 2 5.36 -4.76 22.1 0.2 18.2 0.005 35.0 1489 70
2019-07-17T18:49:38.907Z,1563389378.907 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:49:38.908Z,1563389378.908 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:50:13.635Z,1563389413.635 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:50:13.636Z,1563389413.636 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:50:31.012Z,1563389431.012 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:50:31.013Z,1563389431.013 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:50:53.553Z,1563389453.553 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:50:53.554Z,1563389453.554 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:51:37.603Z,1563389497.603 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:51:37.603Z,1563389497.603 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:52:02.911Z,1563389522.911 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:52:02.912Z,1563389522.912 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:52:09.831Z,1563389529.831 [DVL_micro](ERROR): only read 42 of 46 data items
2019-07-17T18:52:09.831Z,1563389529.831 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -32 -255 999 -100 2 3 6.0 -206.9 165.0 2 -1141 165.0 2 -1376 -2 -1141 2 -0.53 5.67 316.6 -3.0 18.1 0.005 35.0 1489 125
2019-07-17T18:52:19.258Z,1563389539.258 [DVL_micro](ERROR): only read 37 of 46 data items
2019-07-17T18:52:19.258Z,1563389539.258 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 071 35 624 -123 2 2 2 3 -927.6 210.9 125.3 2 -526.3 792.4 125.3 2 -927 210 125 2 -526 792 125 2 -0.15 5.71 316.4 -3..005 35.0 1489 100
2019-07-17T18:52:41.333Z,1563389561.333 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:52:41.334Z,1563389561.334 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:52:58.713Z,1563389578.713 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:52:58.713Z,1563389578.713 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:53:20.627Z,1563389600.627 [CommandLine](IMPORTANT): got command failComponent
2019-07-17T18:53:20.627Z,1563389600.627 [CommandLine](IMPORTANT): Failed components:
2019-07-17T18:53:20.627Z,1563389600.627 [CommandLine](IMPORTANT): No failed Components.
2019-07-17T18:53:23.230Z,1563389603.230 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-17T18:53:23.230Z,1563389603.230 [DVL_micro] Data Fault, FailCount= 1
2019-07-17T18:53:23.230Z,1563389603.230 [DVL_micro](ERROR): Data Fault
2019-07-17T18:53:23.262Z,1563389603.262 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-17T18:53:23.701Z,1563389603.701 [DVL_micro](INFO): uninitialize:Powering down
2019-07-17T18:53:24.478Z,1563389604.478 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-17T18:53:24.478Z,1563389604.478 [DVL_micro] No Fault, FailCount= 1
2019-07-17T18:53:24.854Z,1563389604.854 [DVL_micro](INFO): Initializing
2019-07-17T18:53:25.257Z,1563389605.257 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:53:25.257Z,1563389605.257 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:53:45.869Z,1563389625.869 [NAL9602](INFO): SBD MO Status=2, MOMSN=29894, MT Status=2, MTMSN=0
2019-07-17T18:53:45.870Z,1563389625.870 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:54:16.936Z,1563389656.936 [NAL9602](INFO): SBD MO Status=1, MOMSN=29894, MT Status=0, MTMSN=0
2019-07-17T18:54:16.985Z,1563389656.985 [NAL9602](INFO): Sent 141 bytes from file Logs/20190716T222015/Courier0031.lzma
2019-07-17T18:54:16.985Z,1563389656.985 [NAL9602](INFO): Packets left to send: 0
2019-07-17T18:54:32.551Z,1563389672.551 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:54:32.551Z,1563389672.551 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:55:25.088Z,1563389725.088 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:55:25.088Z,1563389725.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:55:59.898Z,1563389759.898 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:55:59.898Z,1563389759.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:56:25.148Z,1563389785.148 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:56:25.148Z,1563389785.148 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:56:29.588Z,1563389789.588 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-17T18:56:29.588Z,1563389789.588 [DVL_micro] Data Fault, FailCount= 1
2019-07-17T18:56:29.588Z,1563389789.588 [DVL_micro](ERROR): Data Fault
2019-07-17T18:56:29.632Z,1563389789.632 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-17T18:56:30.069Z,1563389790.069 [DVL_micro](INFO): uninitialize:Powering down
2019-07-17T18:56:34.049Z,1563389794.049 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-17T18:56:34.049Z,1563389794.049 [DVL_micro] No Fault, FailCount= 1
2019-07-17T18:56:34.351Z,1563389794.351 [DVL_micro](INFO): Initializing
2019-07-17T18:56:51.313Z,1563389811.313 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:56:51.313Z,1563389811.313 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:57:17.165Z,1563389837.165 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:57:17.165Z,1563389837.165 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:57:50.733Z,1563389870.733 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:57:50.733Z,1563389870.733 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:58:14.770Z,1563389894.770 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-17T18:58:14.770Z,1563389894.770 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 12 -94 -13 -86 2 2 2 2 33.4 -10.7 -48.8 2 16.7 -30.8 -48.8 2 33 -10 -48 2 16 -30 -48 2 -0.57 5.65 316.2 -3.0 18.3 0.005 35.0 1489 73
2019-07-17T18:58:43.982Z,1563389923.982 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:58:43.983Z,1563389923.983 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:59:30.937Z,1563389970.937 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:59:30.937Z,1563389970.937 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T18:59:38.518Z,1563389978.518 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-17T18:59:38.518Z,1563389978.518 [DVL_micro] Data Fault, FailCount= 1
2019-07-17T18:59:38.518Z,1563389978.518 [DVL_micro](ERROR): Data Fault
2019-07-17T18:59:38.585Z,1563389978.585 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-17T18:59:38.961Z,1563389978.961 [DVL_micro](INFO): uninitialize:Powering down
2019-07-17T18:59:41.137Z,1563389981.137 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-17T18:59:41.138Z,1563389981.138 [DVL_micro] No Fault, FailCount= 1
2019-07-17T18:59:41.454Z,1563389981.454 [DVL_micro](INFO): Initializing
2019-07-17T18:59:54.609Z,1563389994.609 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T18:59:54.609Z,1563389994.609 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:00:29.114Z,1563390029.114 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:00:29.114Z,1563390029.114 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:00:43.930Z,1563390043.930 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:00:43.930Z,1563390043.930 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:01:01.162Z,1563390061.162 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:01:01.162Z,1563390061.162 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:01:15.221Z,1563390075.221 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:01:15.222Z,1563390075.222 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:01:34.474Z,1563390094.474 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-07-17T19:01:34.474Z,1563390094.474 [DVL_micro] Communications Fault, FailCount= 1
2019-07-17T19:01:34.474Z,1563390094.474 [DVL_micro](ERROR): Communications Fault
2019-07-17T19:01:34.535Z,1563390094.535 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-07-17T19:01:34.941Z,1563390094.941 [DVL_micro](INFO): uninitialize:Powering down
2019-07-17T19:01:35.716Z,1563390095.716 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-17T19:01:35.717Z,1563390095.717 [DVL_micro] No Fault, FailCount= 1
2019-07-17T19:01:36.090Z,1563390096.090 [DVL_micro](INFO): Initializing
2019-07-17T19:01:38.919Z,1563390098.919 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:01:38.919Z,1563390098.919 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:02:09.818Z,1563390129.818 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:02:09.819Z,1563390129.819 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:02:34.289Z,1563390154.289 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:02:34.289Z,1563390154.289 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:02:42.445Z,1563390162.445 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-17T19:02:42.445Z,1563390162.445 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 0 1 0.2 1.0 0 10.3 -546.7 -329.5 0 231.4 0 0 -221 275 0 0 2 2 0 0 0 0 0 0 0 0 0 0 0 0 4.94 -2.47 16.3 0.2 18.3 0.005 35.0 1489 109
2019-07-17T19:03:12.261Z,1563390192.261 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:03:12.262Z,1563390192.262 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:03:37.191Z,1563390217.191 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:03:37.192Z,1563390217.192 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:03:54.487Z,1563390234.487 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:03:54.488Z,1563390234.488 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:04:13.180Z,1563390253.180 [DVL_micro](ERROR): checksum mismatch: reported94 , calculated:88
2019-07-17T19:04:13.180Z,1563390253.180 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 0 1 9.8 9.7 0 10.2 -9.0 -7.7 0 -0.9 183 -196 1 -130 1 1 5 1 -12.5 -9.1 -4.6 1 -8 -5.9 1 242 -88 -38 2 258 -5 -38 2 4.92 -2.41 18.8 9.7 18.2 0.005 35.0 1489 94
2019-07-17T19:04:29.204Z,1563390269.204 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:04:29.204Z,1563390269.204 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:05:43.990Z,1563390343.990 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:05:43.990Z,1563390343.990 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:05:57.393Z,1563390357.393 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-17T19:05:57.393Z,1563390357.393 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 1.0 0.2 10.2 -571.9 526.8 6600.1 765.9 0 0 0 -754 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 4.92 -2.44 16.1 0.2 18.3 0.005 35.0 1489 118
2019-07-17T19:06:08.715Z,1563390368.715 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:06:08.715Z,1563390368.715 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:06:35.638Z,1563390395.638 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:06:35.638Z,1563390395.638 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:07:10.341Z,1563390430.341 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:07:10.341Z,1563390430.341 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:07:36.107Z,1563390456.107 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:07:36.107Z,1563390456.107 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:07:53.680Z,1563390473.680 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-17T19:07:53.680Z,1563390473.680 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 0.2 1.0458.0 -92.4 6063.7 0 0 0 0 414 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 44 27.8 0.2 18.2 0.005 35.0 1489 116
2019-07-17T19:08:00.985Z,1563390480.985 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:08:00.986Z,1563390480.986 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:08:36.256Z,1563390516.256 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:08:36.257Z,1563390516.257 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:09:05.921Z,1563390545.921 [DVL_micro](ERROR): checksum mismatch: reported76 , calculated:82
2019-07-17T19:09:05.921Z,1563390545.921 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 1.3 0.2 2.7 -660.5 399.374.9 0 0 0 0 0 0 0 0 -4851.8 433.0 751.8 1 -3903.7 -2952.0 583.3 1 0 0 0 0 0 0 0 0 4.94 -2.39 41.5 0.2 18.2 0.005 35.0 1489 76
2019-07-17T19:09:10.774Z,1563390550.774 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-17T19:09:10.774Z,1563390550.774 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 1.3 0.2 2.5 -602.8 -37.8 5968.6 -1201.2 0 0 0 0 0 0 0 0 -8770.4 1552.7 1112.7 1 -7497.5 -4858.6 870.1 1 0 0 0 0 0 0 0 0 4.96 -2.43 42.4 00.005 35.0 1489 116
2019-07-17T19:09:19.247Z,1563390559.247 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:09:19.247Z,1563390559.247 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:09:37.352Z,1563390577.352 [CommandLine](IMPORTANT): got command get DataOverHttps.loadAtStartup
2019-07-17T19:09:37.353Z,1563390577.353 [CommandLine](IMPORTANT): DataOverHttps.loadAtStartup 1 bool
2019-07-17T19:09:41.591Z,1563390581.591 [CommandLine](IMPORTANT): got command failComponent
2019-07-17T19:09:41.591Z,1563390581.591 [CommandLine](IMPORTANT): Failed components:
2019-07-17T19:09:41.591Z,1563390581.591 [CommandLine](IMPORTANT): No failed Components.
2019-07-17T19:09:44.991Z,1563390584.991 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:09:44.991Z,1563390584.991 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:10:13.194Z,1563390613.194 [CommandLine](IMPORTANT): got command get Radio_Surface.loadAtStartup
2019-07-17T19:10:13.195Z,1563390613.195 [CommandLine](IMPORTANT): Radio_Surface.loadAtStartup 0 bool
2019-07-17T19:10:35.681Z,1563390635.681 [CommandLine](IMPORTANT): got command configSet list
2019-07-17T19:10:35.681Z,1563390635.681 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=1 bool;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=6 hour;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): BR_Ping1D.verbosity=1 count;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): CBIT.abortDepth=300 meter;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): CBIT.stopDepth=295 meter;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2019-07-17T19:10:35.682Z,1563390635.682 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=1 bool;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): Express linearApproximation DAT.range 20.000000 meter;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): PAR_Licor.adcCal=8.765e-06 microampere_per_count;

2019-07-17T19:10:35.683Z,1563390635.683 [CommandLine](IMPORTANT): PAR_Licor.darkCount=0 count;

2019-07-17T19:10:35.684Z,1563390635.684 [CommandLine](IMPORTANT): PAR_Licor.multiplier=190.3 micromole_per_second_per_square_meter_per_microampere;

2019-07-17T19:10:35.684Z,1563390635.684 [CommandLine](IMPORTANT): PNI_TCM.loadAtStartup=0 bool;

2019-07-17T19:10:35.684Z,1563390635.684 [CommandLine](IMPORTANT): Radio_Surface.loadAtStartup=0 bool;

2019-07-17T19:10:35.684Z,1563390635.684 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2019-07-17T19:10:35.684Z,1563390635.684 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=90 cubic_centimeter;

2019-07-17T19:10:35.684Z,1563390635.684 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1.4 centimeter;

2019-07-17T19:11:04.119Z,1563390664.119 [NAL9602](INFO): SBD MO Status=2, MOMSN=29895, MT Status=2, MTMSN=0
2019-07-17T19:11:04.119Z,1563390664.119 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-17T19:11:13.347Z,1563390673.347 [CommandLine](IMPORTANT): got command configSet Radio_Surface.loadAtStartup 1.000000 bool persist
2019-07-17T19:11:13.347Z,1563390673.347 [CommandLine](IMPORTANT): configSet Radio_Surface.loadAtStartup requires a restart to take effect.
2019-07-17T19:11:19.227Z,1563390679.227 [CommandLine](IMPORTANT): got command restart application
2019-07-17T19:11:20.233Z,1563390680.233 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-17T19:11:20.233Z,1563390680.233 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.365Z,1563390680.365 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-07-17T19:11:20.365Z,1563390680.365 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.366Z,1563390680.366 [CommandLine](INFO): Join timeout helper Thread ID is 7084
2019-07-17T19:11:20.366Z,1563390680.366 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-07-17T19:11:20.366Z,1563390680.366 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.367Z,1563390680.367 [NavChartDb](INFO): Join timeout helper Thread ID is 7085
2019-07-17T19:11:20.655Z,1563390680.655 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-17T19:11:20.656Z,1563390680.656 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.669Z,1563390680.669 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-07-17T19:11:20.669Z,1563390680.669 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.669Z,1563390680.669 [DataOverHttps](INFO): Join timeout helper Thread ID is 7086
2019-07-17T19:11:20.881Z,1563390680.881 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-17T19:11:20.881Z,1563390680.881 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.885Z,1563390680.885 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-07-17T19:11:20.885Z,1563390680.885 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.885Z,1563390680.885 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7087
2019-07-17T19:11:20.961Z,1563390680.961 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-17T19:11:20.961Z,1563390680.961 [WetLabsBB2FL](INFO): Powering down
2019-07-17T19:11:20.962Z,1563390680.962 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.965Z,1563390680.965 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-07-17T19:11:20.965Z,1563390680.965 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:20.965Z,1563390680.965 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7088
2019-07-17T19:11:21.269Z,1563390681.269 [CTD_Seabird](INFO): Powering down
2019-07-17T19:11:21.281Z,1563390681.281 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-17T19:11:21.281Z,1563390681.281 [CTD_Seabird](INFO): Powering down
2019-07-17T19:11:21.293Z,1563390681.293 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.294Z,1563390681.294 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-07-17T19:11:21.295Z,1563390681.295 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.295Z,1563390681.295 [logger](INFO): Join timeout helper Thread ID is 7089
2019-07-17T19:11:21.333Z,1563390681.333 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-17T19:11:21.333Z,1563390681.333 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.353Z,1563390681.353 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-07-17T19:11:21.354Z,1563390681.354 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.354Z,1563390681.354 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-07-17T19:11:21.354Z,1563390681.354 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.354Z,1563390681.354 [controlThread](INFO): Join timeout helper Thread ID is 7090
2019-07-17T19:11:21.433Z,1563390681.433 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-17T19:11:21.433Z,1563390681.433 [controlThread](DEBUG): Uninitializing ControlThread
2019-07-17T19:11:21.434Z,1563390681.434 [Aanderaa_O2](INFO): Powering down
2019-07-17T19:11:21.461Z,1563390681.461 [AHRS_M2](INFO): Powering down
2019-07-17T19:11:21.605Z,1563390681.605 [DVL_micro](INFO): uninitialize:Powering down
2019-07-17T19:11:21.606Z,1563390681.606 [NAL9602](INFO): Powering down
2019-07-17T19:11:21.607Z,1563390681.607 [DAT](INFO): Powering down
2019-07-17T19:11:21.726Z,1563390681.726 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-07-17T19:11:21.726Z,1563390681.726 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-07-17T19:11:21.727Z,1563390681.727 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-07-17T19:11:21.727Z,1563390681.727 [MissionManager](INFO): Uninitializing Mission Default
2019-07-17T19:11:21.727Z,1563390681.727 [Default] Stopped
2019-07-17T19:11:21.728Z,1563390681.728 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-17T19:11:21.728Z,1563390681.728 [Default:B.GoToSurface] Stopped
2019-07-17T19:11:21.728Z,1563390681.728 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-17T19:11:21.728Z,1563390681.728 [Default:CheckIn] Stopped
2019-07-17T19:11:21.728Z,1563390681.728 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-17T19:11:21.728Z,1563390681.728 [Default:CheckIn:Read_Iridium] Stopped
2019-07-17T19:11:21.730Z,1563390681.730 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-07-17T19:11:21.731Z,1563390681.731 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-07-17T19:11:21.731Z,1563390681.731 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-07-17T19:11:21.731Z,1563390681.731 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-07-17T19:11:21.731Z,1563390681.731 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-07-17T19:11:21.732Z,1563390681.732 [BuoyancyServo](INFO): Powering down
2019-07-17T19:11:21.745Z,1563390681.745 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-07-17T19:11:21.745Z,1563390681.745 [ElevatorServo](INFO): Powering down
2019-07-17T19:11:21.746Z,1563390681.746 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-07-17T19:11:21.746Z,1563390681.746 [MassServo](INFO): Powering down
2019-07-17T19:11:21.747Z,1563390681.747 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-17T19:11:21.747Z,1563390681.747 [RudderServo](INFO): Powering down
2019-07-17T19:11:21.747Z,1563390681.747 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-07-17T19:11:21.748Z,1563390681.748 [ThrusterServo](INFO): Powering down
2019-07-17T19:11:21.748Z,1563390681.748 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-07-17T19:11:21.749Z,1563390681.749 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-07-17T19:11:21.749Z,1563390681.749 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-07-17T19:11:21.749Z,1563390681.749 [CBIT](DEBUG): Powering off loads.
2019-07-17T19:11:21.761Z,1563390681.761 [CBIT](DEBUG): Disabling WDT.
2019-07-17T19:11:21.773Z,1563390681.773 [CBIT](DEBUG): Opening all GF detection circuits.
2019-07-17T19:11:21.773Z,1563390681.773 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.815Z,1563390681.815 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.820Z,1563390681.820 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.889Z,1563390681.889 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:21.937Z,1563390681.937 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-17T19:11:22.002Z,1563390682.002 [logger ThreadHandler](INFO): Thread cancelled.