2023-05-12T20:57:43.131Z,1683925063.131 [Supervisor](DEBUG): Initializing supervisor.
2023-05-12T20:57:43.135Z,1683925063.135 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-12T20:57:43.135Z,1683925063.135 [SyncHandler](INFO): Protected caller Thread ID is 835
2023-05-12T20:57:43.136Z,1683925063.136 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-12T20:57:43.137Z,1683925063.137 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-12T20:57:43.137Z,1683925063.137 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2023-05-12T20:57:43.141Z,1683925063.141 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-12T20:57:43.160Z,1683925063.160 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-12T20:57:43.161Z,1683925063.161 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-12T20:57:43.161Z,1683925063.161 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837
2023-05-12T20:57:43.166Z,1683925063.166 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-12T20:57:43.167Z,1683925063.167 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-12T20:57:43.167Z,1683925063.167 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838
2023-05-12T20:57:43.169Z,1683925063.169 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-12T20:57:43.170Z,1683925063.170 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-12T20:57:43.170Z,1683925063.170 [logger ThreadHandler](INFO): Protected caller Thread ID is 839
2023-05-12T20:57:43.174Z,1683925063.174 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-12T20:57:43.175Z,1683925063.175 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-12T20:57:43.179Z,1683925063.179 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-12T20:57:43.541Z,1683925063.541 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-12T20:57:43.541Z,1683925063.541 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-12T20:57:44.272Z,1683925064.272 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-12T20:57:44.274Z,1683925064.274 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-12T20:57:44.384Z,1683925064.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-12T20:57:44.385Z,1683925064.385 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-12T20:57:44.905Z,1683925064.905 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-12T20:57:44.907Z,1683925064.907 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-12T20:57:45.005Z,1683925065.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-12T20:57:45.007Z,1683925065.007 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-12T20:57:45.088Z,1683925065.088 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-12T20:57:45.513Z,1683925065.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-12T20:57:45.515Z,1683925065.515 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-12T20:57:45.744Z,1683925065.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-12T20:57:45.745Z,1683925065.745 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-12T20:57:45.884Z,1683925065.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-12T20:57:45.886Z,1683925065.886 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-12T20:57:46.135Z,1683925066.135 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-12T20:57:46.137Z,1683925066.137 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-12T20:57:46.689Z,1683925066.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-12T20:57:46.689Z,1683925066.689 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-12T20:57:47.877Z,1683925067.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-12T20:57:47.878Z,1683925067.878 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-12T20:57:47.995Z,1683925067.995 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-12T20:57:48.196Z,1683925068.196 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-12T20:57:48.198Z,1683925068.198 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-12T20:57:48.425Z,1683925068.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-12T20:57:48.426Z,1683925068.426 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-12T20:57:48.735Z,1683925068.735 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-12T20:57:48.737Z,1683925068.737 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2023-05-12T20:57:48.742Z,1683925068.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2023-05-12T20:57:48.853Z,1683925068.853 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2023-05-12T20:57:49.009Z,1683925069.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2023-05-12T20:57:49.097Z,1683925069.097 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2023-05-12T20:57:49.181Z,1683925069.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2023-05-12T20:57:49.293Z,1683925069.293 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2023-05-12T20:57:49.476Z,1683925069.476 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2023-05-12T20:57:49.744Z,1683925069.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-12T20:57:49.745Z,1683925069.745 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2023-05-12T20:57:49.882Z,1683925069.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2023-05-12T20:57:49.978Z,1683925069.978 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2023-05-12T20:57:50.086Z,1683925070.086 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2023-05-12T20:57:50.191Z,1683925070.191 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-12T20:57:50.215Z,1683925070.215 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-12T20:57:50.340Z,1683925070.340 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-12T20:57:50.341Z,1683925070.341 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-12T20:57:50.357Z,1683925070.357 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-12T20:57:50.357Z,1683925070.357 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-12T20:57:50.429Z,1683925070.429 [DepthRateCalculator] Loaded
2023-05-12T20:57:50.429Z,1683925070.429 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-12T20:57:50.435Z,1683925070.435 [PitchRateCalculator] Loaded
2023-05-12T20:57:50.435Z,1683925070.435 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-12T20:57:50.446Z,1683925070.446 [SpeedCalculator] Loaded
2023-05-12T20:57:50.446Z,1683925070.446 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-12T20:57:50.462Z,1683925070.462 [VerticalHomogeneityIndexCalculator] Loaded
2023-05-12T20:57:50.462Z,1683925070.462 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2023-05-12T20:57:50.467Z,1683925070.467 [YawRateCalculator] Loaded
2023-05-12T20:57:50.467Z,1683925070.467 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-12T20:57:50.489Z,1683925070.489 [ElevatorOffsetCalculator] Loaded
2023-05-12T20:57:50.490Z,1683925070.490 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-12T20:57:50.490Z,1683925070.490 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-12T20:57:50.491Z,1683925070.491 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-12T20:57:50.558Z,1683925070.558 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-12T20:57:50.616Z,1683925070.616 [VerticalControl] Loaded
2023-05-12T20:57:50.616Z,1683925070.616 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-12T20:57:50.619Z,1683925070.619 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-12T20:57:50.660Z,1683925070.660 [HorizontalControl] Loaded
2023-05-12T20:57:50.661Z,1683925070.661 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-12T20:57:50.663Z,1683925070.663 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-12T20:57:50.666Z,1683925070.666 [SpeedControl] Loaded
2023-05-12T20:57:50.666Z,1683925070.666 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-12T20:57:50.669Z,1683925070.669 [LoopControl](DEBUG): Construct LoopControl.
2023-05-12T20:57:50.669Z,1683925070.669 [LoopControl] Loaded
2023-05-12T20:57:50.670Z,1683925070.670 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-12T20:57:50.670Z,1683925070.670 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-12T20:57:50.671Z,1683925070.671 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-12T20:57:50.808Z,1683925070.808 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-12T20:57:50.808Z,1683925070.808 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-12T20:57:50.822Z,1683925070.822 [NavChart] Loaded
2023-05-12T20:57:50.822Z,1683925070.822 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-12T20:57:50.828Z,1683925070.828 [UniversalFixResidualReporter] Loaded
2023-05-12T20:57:50.828Z,1683925070.828 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-12T20:57:50.828Z,1683925070.828 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-12T20:57:50.829Z,1683925070.829 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-12T20:57:51.017Z,1683925071.017 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-12T20:57:51.018Z,1683925071.018 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-12T20:57:51.814Z,1683925071.814 [AHRS_M2] Loaded
2023-05-12T20:57:51.814Z,1683925071.814 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-12T20:57:52.065Z,1683925072.065 [BackseatComponent] Loaded
2023-05-12T20:57:52.065Z,1683925072.065 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-12T20:57:52.066Z,1683925072.066 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2023-05-12T20:57:52.066Z,1683925072.066 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 921
2023-05-12T20:57:52.069Z,1683925072.069 [LcmUniversalReporter] Loaded
2023-05-12T20:57:52.069Z,1683925072.069 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-12T20:57:53.363Z,1683925073.363 [BPC1] Loaded
2023-05-12T20:57:53.363Z,1683925073.363 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-12T20:57:53.454Z,1683925073.454 [DAT] Loaded
2023-05-12T20:57:53.454Z,1683925073.454 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-05-12T20:57:53.455Z,1683925073.455 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2023-05-12T20:57:53.455Z,1683925073.455 [DAT ThreadHandler](INFO): Protected caller Thread ID is 922
2023-05-12T20:57:53.597Z,1683925073.597 [DataOverHttps] Loaded
2023-05-12T20:57:53.597Z,1683925073.597 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-12T20:57:53.598Z,1683925073.598 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2023-05-12T20:57:53.599Z,1683925073.599 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923
2023-05-12T20:57:53.620Z,1683925073.620 [Depth_Keller] Loaded
2023-05-12T20:57:53.620Z,1683925073.620 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-12T20:57:53.625Z,1683925073.625 [DropWeight] Loaded
2023-05-12T20:57:53.625Z,1683925073.625 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-05-12T20:57:53.663Z,1683925073.663 [DVL_micro] Loaded
2023-05-12T20:57:53.664Z,1683925073.664 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-05-12T20:57:53.726Z,1683925073.726 [NAL9602] Loaded
2023-05-12T20:57:53.726Z,1683925073.726 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-12T20:57:53.757Z,1683925073.757 [Onboard] Loaded
2023-05-12T20:57:53.757Z,1683925073.757 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-12T20:57:53.758Z,1683925073.758 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4099D4E0
2023-05-12T20:57:53.758Z,1683925073.758 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924
2023-05-12T20:57:53.771Z,1683925073.771 [Power24vConverter] Loaded
2023-05-12T20:57:53.771Z,1683925073.771 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-12T20:57:53.784Z,1683925073.784 [Radio_Surface] Loaded
2023-05-12T20:57:53.784Z,1683925073.784 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-12T20:57:53.785Z,1683925073.785 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409CD4E0
2023-05-12T20:57:53.786Z,1683925073.786 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925
2023-05-12T20:57:53.787Z,1683925073.787 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-12T20:57:53.788Z,1683925073.788 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-12T20:57:53.964Z,1683925073.964 [BuoyancyServo] Loaded
2023-05-12T20:57:53.965Z,1683925073.965 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-12T20:57:53.986Z,1683925073.986 [ElevatorServo] Loaded
2023-05-12T20:57:53.986Z,1683925073.986 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-12T20:57:54.006Z,1683925074.006 [MassServo] Loaded
2023-05-12T20:57:54.006Z,1683925074.006 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-12T20:57:54.025Z,1683925074.025 [RudderServo] Loaded
2023-05-12T20:57:54.025Z,1683925074.025 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-12T20:57:54.040Z,1683925074.040 [ThrusterHE] Loaded
2023-05-12T20:57:54.040Z,1683925074.040 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-12T20:57:54.041Z,1683925074.041 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-12T20:57:54.041Z,1683925074.041 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-12T20:57:54.154Z,1683925074.154 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.100000 degC
2023-05-12T20:57:54.154Z,1683925074.154 [StratificationFrontDetector](INFO): (re)initializing
2023-05-12T20:57:54.154Z,1683925074.154 [StratificationFrontDetector] Loaded
2023-05-12T20:57:54.154Z,1683925074.154 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2023-05-12T20:57:54.155Z,1683925074.155 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-12T20:57:54.155Z,1683925074.155 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-12T20:57:54.200Z,1683925074.200 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-12T20:57:54.200Z,1683925074.200 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-12T20:57:54.939Z,1683925074.939 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-12T20:57:54.940Z,1683925074.940 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-12T20:57:55.163Z,1683925075.163 [CTD_Seabird] Loaded
2023-05-12T20:57:55.164Z,1683925075.164 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-12T20:57:55.165Z,1683925075.165 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0
2023-05-12T20:57:55.165Z,1683925075.165 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 926
2023-05-12T20:57:55.199Z,1683925075.199 [ESPComponent] Loaded
2023-05-12T20:57:55.200Z,1683925075.200 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-12T20:57:55.220Z,1683925075.220 [PAR_Licor] Loaded
2023-05-12T20:57:55.220Z,1683925075.220 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-12T20:57:55.252Z,1683925075.252 [WetLabsBB2FL] Loaded
2023-05-12T20:57:55.252Z,1683925075.252 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-12T20:57:55.253Z,1683925075.253 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0
2023-05-12T20:57:55.254Z,1683925075.254 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 927
2023-05-12T20:57:55.255Z,1683925075.255 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-12T20:57:55.257Z,1683925075.257 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-12T20:57:55.428Z,1683925075.428 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-12T20:57:55.437Z,1683925075.437 [SBIT] Loaded
2023-05-12T20:57:55.437Z,1683925075.437 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-12T20:57:55.440Z,1683925075.440 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-12T20:57:55.453Z,1683925075.453 [IBIT] Loaded
2023-05-12T20:57:55.454Z,1683925075.454 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-12T20:57:55.460Z,1683925075.460 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-12T20:57:55.568Z,1683925075.568 [CBIT] Loaded
2023-05-12T20:57:55.569Z,1683925075.569 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-12T20:57:55.569Z,1683925075.569 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-12T20:57:55.576Z,1683925075.576 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-12T20:57:55.579Z,1683925075.579 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-12T20:57:55.590Z,1683925075.590 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-12T20:57:55.591Z,1683925075.591 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C014E0
2023-05-12T20:57:55.591Z,1683925075.591 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928
2023-05-12T20:57:55.596Z,1683925075.596 [Supervisor](INFO): Main Thread ID is 827
2023-05-12T20:57:55.596Z,1683925075.596 [Supervisor](DEBUG): Running supervisor.
2023-05-12T20:57:55.597Z,1683925075.597 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929
2023-05-12T20:57:55.597Z,1683925075.597 [CommandExec](INFO): Initializing the command executive.
2023-05-12T20:57:55.599Z,1683925075.599 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930
2023-05-12T20:57:55.601Z,1683925075.601 [controlThread ThreadHandler](INFO): Handler Thread ID is 931
2023-05-12T20:57:55.601Z,1683925075.601 [controlThread](DEBUG): Initializing ControlThread
2023-05-12T20:57:55.602Z,1683925075.602 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-12T20:57:55.603Z,1683925075.603 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-12T20:57:55.603Z,1683925075.603 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-12T20:57:55.603Z,1683925075.603 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2023-05-12T20:57:55.604Z,1683925075.604 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-12T20:57:55.605Z,1683925075.605 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-12T20:57:55.605Z,1683925075.605 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-12T20:57:55.607Z,1683925075.607 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-12T20:57:55.608Z,1683925075.608 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-12T20:57:55.608Z,1683925075.608 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-12T20:57:55.609Z,1683925075.609 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-12T20:57:55.609Z,1683925075.609 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-12T20:57:55.619Z,1683925075.619 [SBIT](INFO): Initialize SBIT Component.
2023-05-12T20:57:55.620Z,1683925075.620 [SBIT](IMPORTANT): git: 2023-05-12
2023-05-12T20:57:55.620Z,1683925075.620 [SBIT](INFO): git hash: e578d619fb9973b827c94456cbab8bc18b161215
2023-05-12T20:57:55.620Z,1683925075.620 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-12T20:57:55.621Z,1683925075.621 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-05-12T20:57:55.622Z,1683925075.622 [SBIT](INFO): Beginning SBIT in 134.000000 seconds.
2023-05-12T20:57:55.623Z,1683925075.623 [IBIT](INFO): Initialize IBIT Component.
2023-05-12T20:57:55.624Z,1683925075.624 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-12T20:57:55.625Z,1683925075.625 [logger ThreadHandler](INFO): Handler Thread ID is 932
2023-05-12T20:57:55.635Z,1683925075.635 [CBIT](DEBUG): Initialized mux pins.
2023-05-12T20:57:55.635Z,1683925075.635 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-12T20:57:55.643Z,1683925075.643 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 933
2023-05-12T20:57:55.655Z,1683925075.655 [DAT ThreadHandler](INFO): Handler Thread ID is 934
2023-05-12T20:57:55.656Z,1683925075.656 [DAT](INFO): Powering up
2023-05-12T20:57:55.656Z,1683925075.656 [DAT](DEBUG): Initializing DAT.
2023-05-12T20:57:55.659Z,1683925075.659 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-12T20:57:55.659Z,1683925075.659 [CBIT](DEBUG): Initializing heartbeat.
2023-05-12T20:57:55.661Z,1683925075.661 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 936
2023-05-12T20:57:55.662Z,1683925075.662 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-12T20:57:55.671Z,1683925075.671 [Onboard ThreadHandler](INFO): Handler Thread ID is 937
2023-05-12T20:57:55.689Z,1683925075.689 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 938
2023-05-12T20:57:55.711Z,1683925075.711 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 939
2023-05-12T20:57:55.712Z,1683925075.712 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-12T20:57:55.716Z,1683925075.716 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 941
2023-05-12T20:57:55.719Z,1683925075.719 [WetLabsBB2FL](INFO): Powering up
2023-05-12T20:57:55.720Z,1683925075.720 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943
2023-05-12T20:57:55.729Z,1683925075.729 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-12T20:57:55.729Z,1683925075.729 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-12T20:57:55.729Z,1683925075.729 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-12T20:57:55.729Z,1683925075.729 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-12T20:57:55.730Z,1683925075.730 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-12T20:57:55.730Z,1683925075.730 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-12T20:57:55.730Z,1683925075.730 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-12T20:57:55.730Z,1683925075.730 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-12T20:57:55.731Z,1683925075.731 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-12T20:57:55.731Z,1683925075.731 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-12T20:57:55.771Z,1683925075.771 [CBIT](DEBUG): Backplane powered.
2023-05-12T20:57:55.772Z,1683925075.772 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-12T20:57:55.800Z,1683925075.800 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-12T20:57:55.844Z,1683925075.844 [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>


2023-05-12T20:57:55.844Z,1683925075.844 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-12T20:57:55.921Z,1683925075.921 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-12T20:57:55.922Z,1683925075.922 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-12T20:57:55.940Z,1683925075.940 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-12T20:57:55.984Z,1683925075.984 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-12T20:57:55.986Z,1683925075.986 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-12T20:57:56.004Z,1683925076.004 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-12T20:57:56.026Z,1683925076.026 [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="P4H">
                <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>


2023-05-12T20:57:56.031Z,1683925076.031 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-12T20:57:56.043Z,1683925076.043 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-12T20:57:56.095Z,1683925076.095 [Radio_Surface](INFO): Powering up
2023-05-12T20:57:56.240Z,1683925076.240 [Power24vConverter](INFO): Powering up.
2023-05-12T20:57:56.289Z,1683925076.289 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-12T20:57:56.295Z,1683925076.295 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-12T20:57:56.296Z,1683925076.296 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-12T20:57:56.303Z,1683925076.303 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-12T20:57:56.304Z,1683925076.304 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-12T20:57:56.311Z,1683925076.311 [MassServo](DEBUG): Initializing MassServo.
2023-05-12T20:57:56.312Z,1683925076.312 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-12T20:57:56.319Z,1683925076.319 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-12T20:57:56.320Z,1683925076.320 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-12T20:57:56.327Z,1683925076.327 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-12T20:57:58.331Z,1683925078.331 [WetLabsBB2FL](INFO): Powering down
2023-05-12T20:58:01.796Z,1683925081.796 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-12T20:58:02.743Z,1683925082.743 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-05-12T20:58:07.499Z,1683925087.499 [DAT](INFO): DAT read: 

2023-05-12T20:58:07.501Z,1683925087.501 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-12T20:58:09.019Z,1683925089.019 [DAT](INFO): DAT read: MF Frequency Band

2023-05-12T20:58:09.268Z,1683925089.268 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-12T20:58:09.269Z,1683925089.269 [DAT](INFO): DAT read: May 12 2023 20:57:51 

2023-05-12T20:58:10.276Z,1683925090.276 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-05-12T20:58:10.277Z,1683925090.277 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-12T20:58:10.278Z,1683925090.278 [DAT](INFO): commRate: 800
2023-05-12T20:58:12.355Z,1683925092.355 [DAT](INFO): entering command mode
2023-05-12T20:58:12.355Z,1683925092.355 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:12.546Z,1683925092.546 [DAT](INFO): DAT read: r:1>

2023-05-12T20:58:12.547Z,1683925092.547 [DAT](INFO): unknown deviceResponse_: r:1>

2023-05-12T20:58:12.548Z,1683925092.548 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:12.548Z,1683925092.548 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:12.795Z,1683925092.795 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:12.795Z,1683925092.795 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.047Z,1683925093.047 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.047Z,1683925093.047 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.299Z,1683925093.299 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.299Z,1683925093.299 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.551Z,1683925093.551 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.551Z,1683925093.551 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.803Z,1683925093.803 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:13.803Z,1683925093.803 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.055Z,1683925094.055 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.055Z,1683925094.055 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.307Z,1683925094.307 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.307Z,1683925094.307 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.559Z,1683925094.559 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.559Z,1683925094.559 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.811Z,1683925094.811 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:14.811Z,1683925094.811 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.063Z,1683925095.063 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.063Z,1683925095.063 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.315Z,1683925095.315 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.315Z,1683925095.315 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.568Z,1683925095.568 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.568Z,1683925095.568 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.819Z,1683925095.819 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:15.819Z,1683925095.819 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.073Z,1683925096.073 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.074Z,1683925096.074 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.323Z,1683925096.323 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.323Z,1683925096.323 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.575Z,1683925096.575 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.575Z,1683925096.575 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.827Z,1683925096.827 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:16.827Z,1683925096.827 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.081Z,1683925097.081 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.082Z,1683925097.082 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.331Z,1683925097.331 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.331Z,1683925097.331 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.583Z,1683925097.583 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.583Z,1683925097.583 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.835Z,1683925097.835 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:17.835Z,1683925097.835 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.087Z,1683925098.087 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.087Z,1683925098.087 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.347Z,1683925098.347 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.347Z,1683925098.347 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.600Z,1683925098.600 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.600Z,1683925098.600 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.851Z,1683925098.851 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:18.851Z,1683925098.851 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.103Z,1683925099.103 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.103Z,1683925099.103 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.356Z,1683925099.356 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.356Z,1683925099.356 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.607Z,1683925099.607 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.607Z,1683925099.607 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.859Z,1683925099.859 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:19.859Z,1683925099.859 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.111Z,1683925100.111 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.111Z,1683925100.111 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.363Z,1683925100.363 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.363Z,1683925100.363 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.615Z,1683925100.615 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.615Z,1683925100.615 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.867Z,1683925100.867 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:20.867Z,1683925100.867 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.119Z,1683925101.119 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.119Z,1683925101.119 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.371Z,1683925101.371 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.371Z,1683925101.371 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.623Z,1683925101.623 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.623Z,1683925101.623 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.875Z,1683925101.875 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:21.875Z,1683925101.875 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.127Z,1683925102.127 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.127Z,1683925102.127 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.379Z,1683925102.379 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.379Z,1683925102.379 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.631Z,1683925102.631 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.631Z,1683925102.631 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.883Z,1683925102.883 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:22.883Z,1683925102.883 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.135Z,1683925103.135 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.135Z,1683925103.135 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.387Z,1683925103.387 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.387Z,1683925103.387 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.639Z,1683925103.639 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.639Z,1683925103.639 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.891Z,1683925103.891 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.891Z,1683925103.891 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:23.934Z,1683925103.934 [NAL9602](INFO): Powering up NAL9602
2023-05-12T20:58:24.143Z,1683925104.143 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:24.143Z,1683925104.143 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:24.395Z,1683925104.395 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:24.395Z,1683925104.395 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:24.647Z,1683925104.647 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:24.647Z,1683925104.647 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:24.899Z,1683925104.899 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:24.899Z,1683925104.899 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.151Z,1683925105.151 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.151Z,1683925105.151 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.403Z,1683925105.403 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.403Z,1683925105.403 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.655Z,1683925105.655 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.655Z,1683925105.655 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.907Z,1683925105.907 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:25.907Z,1683925105.907 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.161Z,1683925106.161 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.162Z,1683925106.162 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.411Z,1683925106.411 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.411Z,1683925106.411 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.663Z,1683925106.663 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.663Z,1683925106.663 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.915Z,1683925106.915 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:26.915Z,1683925106.915 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:27.167Z,1683925107.167 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:27.167Z,1683925107.167 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:27.419Z,1683925107.419 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:27.419Z,1683925107.419 [DAT](FAULT): failed to enter command mode
2023-05-12T20:58:27.735Z,1683925107.735 [DAT](INFO): entering command mode
2023-05-12T20:58:27.735Z,1683925107.735 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T20:58:27.923Z,1683925107.923 [DAT](INFO): DAT read: 

2023-05-12T20:58:27.924Z,1683925107.924 [DAT](INFO): DAT read: Command '+++' not found

2023-05-12T20:58:27.924Z,1683925107.924 [DAT](INFO): DAT read: Error

2023-05-12T20:58:27.925Z,1683925107.925 [DAT](INFO): setting verbose to 3
2023-05-12T20:58:28.175Z,1683925108.175 [DAT](INFO): DAT read: user:2>

2023-05-12T20:58:28.176Z,1683925108.176 [DAT](INFO): DAT read: Verbose         | 3           

2023-05-12T20:58:28.177Z,1683925108.177 [DAT](INFO): set verbose to 3
2023-05-12T20:58:28.177Z,1683925108.177 [DAT](INFO): setting DatVerbose to 27440
2023-05-12T20:58:28.427Z,1683925108.427 [DAT](INFO): DAT read: user:3>

2023-05-12T20:58:28.428Z,1683925108.428 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-05-12T20:58:28.429Z,1683925108.429 [DAT](INFO): set DatVerbose to 27440
2023-05-12T20:58:28.429Z,1683925108.429 [DAT](INFO): setting transmit power to 8
2023-05-12T20:58:28.679Z,1683925108.679 [DAT](INFO): DAT read: user:4>

2023-05-12T20:58:28.680Z,1683925108.680 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-05-12T20:58:28.681Z,1683925108.681 [DAT](INFO): set transmit power to 8
2023-05-12T20:58:28.681Z,1683925108.681 [DAT](INFO): setting local address to 11
2023-05-12T20:58:28.931Z,1683925108.931 [DAT](INFO): DAT read: user:5>

2023-05-12T20:58:28.932Z,1683925108.932 [DAT](INFO): DAT read: LocalAddr       | 11          

2023-05-12T20:58:28.933Z,1683925108.933 [DAT](INFO): set local address to 11
2023-05-12T20:58:28.934Z,1683925108.934 [DAT](INFO): Setting time to: 20:58:28 And date to:5/12/2023
2023-05-12T20:58:29.183Z,1683925109.183 [DAT](INFO): DAT read: user:6>

2023-05-12T20:58:29.184Z,1683925109.184 [DAT](INFO): DAT read: Fri May 12, 2023  20:58:28  

2023-05-12T20:58:29.185Z,1683925109.185 [DAT](INFO): Local DAT time set to Fri May 12, 2023  20:58:28  

2023-05-12T20:58:34.833Z,1683925114.833 [NAL9602](INFO): NAL9602 initialized
2023-05-12T21:00:09.370Z,1683925209.370 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005255
2023-05-12T21:00:10.201Z,1683925210.201 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-12T21:00:10.205Z,1683925210.205 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-12T21:00:11.104Z,1683925211.104 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-05-12T21:00:11.105Z,1683925211.105 [DVL_micro] Communications Fault, FailCount= 1
2023-05-12T21:00:11.105Z,1683925211.105 [DVL_micro](ERROR): Communications Fault
2023-05-12T21:00:11.198Z,1683925211.198 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-05-12T21:00:11.467Z,1683925211.467 [DVL_micro](INFO): Powering down
2023-05-12T21:00:12.319Z,1683925212.319 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-05-12T21:00:12.319Z,1683925212.319 [DVL_micro] No Fault, FailCount= 1
2023-05-12T21:00:20.701Z,1683925220.701 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.006112
CHAN A1 (24V): -0.002495
CHAN A2 (12V): -0.000061
CHAN A3 (5V): -0.000354
CHAN B0 (3.3V): 0.001236
CHAN B1 (3.15aV): 0.001325
CHAN B2 (3.15bV): 0.000586
CHAN B3 (GND): 0.000582
OPEN: 0.005024
Full Scale: +/- 1 mA
2023-05-12T21:00:30.392Z,1683925230.392 [DVL_micro](ERROR): only read 3 of 4 data items
2023-05-12T21:00:30.392Z,1683925230.392 [DVL_micro](ERROR): Failed to parse:
:BI,-00536,-0995,+00000,I
2023-05-12T21:00:55.878Z,1683925255.878 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-05-12T21:00:55.878Z,1683925255.878 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:00:55.946Z,1683925255.946 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:00:56.318Z,1683925256.318 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:00:56.318Z,1683925256.318 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-05-12T21:01:04.348Z,1683925264.348 [SBIT](IMPORTANT): SBIT PASSED
2023-05-12T21:01:04.348Z,1683925264.348 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-12T21:01:04.349Z,1683925264.349 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=12 count;

2023-05-12T21:01:04.349Z,1683925264.349 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2023-05-12T21:01:04.349Z,1683925264.349 [SBIT](IMPORTANT): Depth_Keller.offset=3.6 decibar;

2023-05-12T21:01:04.349Z,1683925264.349 [SBIT](IMPORTANT): Express none CBIT.ampHoursUsed;

2023-05-12T21:01:04.350Z,1683925264.350 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_salinity_homogeneity_index 0.050000 practical_salinity_unit;

2023-05-12T21:01:04.350Z,1683925264.350 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-05-12T21:01:04.350Z,1683925264.350 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-12T21:01:04.350Z,1683925264.350 [SBIT](IMPORTANT): Express none height_above_sea_floor;

2023-05-12T21:01:04.350Z,1683925264.350 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-05-12T21:01:04.350Z,1683925264.350 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.1 celsius;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=208.617815 cubic_centimeter;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalControl.massDefault=28.688721 millimeter;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalControl.massPositionLimitAft=-28 millimeter;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalControl.massPositionLimitFwd=32 millimeter;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalControl.surfaceThreshold=1.5 meter;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth1=3 meter;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth2=5 meter;

2023-05-12T21:01:04.351Z,1683925264.351 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=10 meter;

2023-05-12T21:01:04.352Z,1683925264.352 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=15 meter;

2023-05-12T21:01:04.352Z,1683925264.352 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-05-12T21:01:04.749Z,1683925264.749 [MissionManager](IMPORTANT): Started mission Startup
2023-05-12T21:01:04.750Z,1683925264.750 [Startup] Running Loop=1
2023-05-12T21:01:04.750Z,1683925264.750 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-12T21:01:04.750Z,1683925264.750 [Startup:A.GoToSurface] Running Loop=1
2023-05-12T21:01:04.750Z,1683925264.750 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-12T21:01:04.751Z,1683925264.751 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-12T21:01:04.752Z,1683925264.752 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-12T21:01:04.752Z,1683925264.752 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-12T21:01:04.752Z,1683925264.752 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-12T21:01:04.753Z,1683925264.753 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-12T21:01:04.754Z,1683925264.754 [Startup:StartupSatComms] Running Loop=1
2023-05-12T21:01:04.754Z,1683925264.754 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-12T21:01:04.754Z,1683925264.754 [Startup:StartupSatComms:A] Running Loop=1
2023-05-12T21:01:05.134Z,1683925265.134 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-12T21:01:16.871Z,1683925276.871 [DAT](INFO): DAT read: user:7>Lowpower

2023-05-12T21:01:16.872Z,1683925276.872 [DAT](DEBUG): Re-entering command mode due to deviceResponse_: user:7>Lowpower

2023-05-12T21:02:04.925Z,1683925324.925 [Startup:StartupSatComms:A](INFO): Timed out from 2023-05-12T21:01:04.8Z
2023-05-12T21:02:04.925Z,1683925324.925 [Startup:StartupSatComms:A] Stopped
2023-05-12T21:02:04.925Z,1683925324.925 [Startup:StartupSatComms:B] Running Loop=1
2023-05-12T21:02:05.329Z,1683925325.329 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-12T21:02:06.204Z,1683925326.204 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T21:02:11.618Z,1683925331.618 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230512T192746/Courier0022.lzma
2023-05-12T21:02:12.620Z,1683925332.620 [DataOverHttps](INFO): Moved sent file to Logs/20230512T192746/Courier0022.lzma.bak
2023-05-12T21:02:12.620Z,1683925332.620 [DataOverHttps](INFO): SBD MOMSN=18301270
2023-05-12T21:02:28.114Z,1683925348.114 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230512T205743/Courier0000.lzma
2023-05-12T21:02:29.116Z,1683925349.116 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0000.lzma.bak
2023-05-12T21:02:29.116Z,1683925349.116 [DataOverHttps](INFO): SBD MOMSN=18301272
2023-05-12T21:03:01.243Z,1683925381.243 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-12T21:03:05.238Z,1683925385.238 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-12T21:02:04.9Z
2023-05-12T21:03:05.238Z,1683925385.238 [Startup:StartupSatComms:B] Stopped
2023-05-12T21:03:05.238Z,1683925385.238 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-12T21:03:05.238Z,1683925385.238 [Startup:StartupSatComms] Stopped
2023-05-12T21:03:05.238Z,1683925385.238 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-12T21:03:05.243Z,1683925385.243 [Startup](INFO): Completed Startup
2023-05-12T21:03:05.243Z,1683925385.243 [MissionManager](INFO): Startup is completed.
2023-05-12T21:03:05.243Z,1683925385.243 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-12T21:03:05.243Z,1683925385.243 [Startup] Stopped
2023-05-12T21:03:05.244Z,1683925385.244 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-12T21:03:05.244Z,1683925385.244 [Startup:A.GoToSurface] Stopped
2023-05-12T21:03:05.244Z,1683925385.244 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-12T21:03:05.636Z,1683925385.636 [MissionManager](IMPORTANT): Started mission Default
2023-05-12T21:03:05.636Z,1683925385.636 [Default] Running Loop=1
2023-05-12T21:03:05.637Z,1683925385.637 [Default](DEBUG): Aggregate::initialize Default
2023-05-12T21:03:05.637Z,1683925385.637 [Default:B.GoToSurface] Running Loop=1
2023-05-12T21:03:05.637Z,1683925385.637 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-12T21:03:05.637Z,1683925385.637 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-12T21:03:05.637Z,1683925385.637 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-12T21:03:05.638Z,1683925385.638 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-12T21:03:05.638Z,1683925385.638 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-12T21:03:05.642Z,1683925385.642 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-12T21:03:05.643Z,1683925385.643 [Default:A.Wait] Running Loop=1
2023-05-12T21:03:05.643Z,1683925385.643 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:03:16.874Z,1683925396.874 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230512T192746/Express0023.lzma
2023-05-12T21:03:17.876Z,1683925397.876 [DataOverHttps](INFO): Moved sent file to Logs/20230512T192746/Express0023.lzma.bak
2023-05-12T21:03:17.876Z,1683925397.876 [DataOverHttps](INFO): SBD MOMSN=18301275
2023-05-12T21:03:18.958Z,1683925398.958 [Default:A.Wait](INFO): Done Waiting.
2023-05-12T21:03:18.958Z,1683925398.958 [Default:A.Wait] Stopped
2023-05-12T21:03:18.958Z,1683925398.958 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:03:19.338Z,1683925399.338 [Default:CheckIn] Running Loop=1
2023-05-12T21:03:19.338Z,1683925399.338 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:03:19.338Z,1683925399.338 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:03:19.746Z,1683925399.746 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-12T21:03:38.726Z,1683925418.726 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-12T21:03:52.044Z,1683925432.044 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:03:56.914Z,1683925436.914 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-05-12T21:03:56.914Z,1683925436.914 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:03:56.925Z,1683925436.925 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:03:57.335Z,1683925437.335 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:03:57.335Z,1683925437.335 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-05-12T21:04:06.587Z,1683925446.587 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:04:21.131Z,1683925461.131 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:04:36.084Z,1683925476.084 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:04:50.635Z,1683925490.635 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:05:05.576Z,1683925505.576 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:05:20.923Z,1683925520.923 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:05:35.871Z,1683925535.871 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:05:50.819Z,1683925550.819 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:06:05.767Z,1683925565.767 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:06:20.715Z,1683925580.715 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-05-12T21:06:20.722Z,1683925580.722 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 4.
2023-05-12T21:06:20.737Z,1683925580.737 [BPC1](INFO): Received data from all battery sticks.
2023-05-12T21:06:43.807Z,1683925603.807 [DVL_micro](ERROR): only read 0 of 4 data items
2023-05-12T21:06:43.807Z,1683925603.807 [DVL_micro](ERROR): Failed to parse:
:RD9,+9999.99,+9999.99,+9999.99
2023-05-12T21:06:49.010Z,1683925609.010 [DVL_micro](ERROR): only read 3 of 4 data items
2023-05-12T21:06:49.010Z,1683925609.010 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+99999.99,+9999.99
2023-05-12T21:06:57.920Z,1683925617.920 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-05-12T21:06:57.920Z,1683925617.920 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:06:57.931Z,1683925617.931 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:06:58.337Z,1683925618.337 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:06:58.337Z,1683925618.337 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-05-12T21:08:19.508Z,1683925699.508 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T21:03:19.3Z
2023-05-12T21:08:19.509Z,1683925699.509 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:08:19.509Z,1683925699.509 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:08:19.920Z,1683925699.920 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-12T21:08:27.210Z,1683925707.210 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230512T205743/Courier0004.lzma
2023-05-12T21:08:28.212Z,1683925708.212 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0004.lzma.bak
2023-05-12T21:08:28.212Z,1683925708.212 [DataOverHttps](INFO): SBD MOMSN=18301341
2023-05-12T21:08:35.670Z,1683925715.670 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-12T21:08:35.670Z,1683925715.670 [NAL9602] Data Fault, FailCount= 1
2023-05-12T21:08:35.670Z,1683925715.670 [NAL9602](ERROR): Data Fault
2023-05-12T21:08:35.720Z,1683925715.720 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-12T21:08:36.057Z,1683925716.057 [NAL9602](INFO): Powering down
2023-05-12T21:08:36.900Z,1683925716.900 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-12T21:08:36.901Z,1683925716.901 [NAL9602] No Fault, FailCount= 1
2023-05-12T21:08:43.756Z,1683925723.756 [DataOverHttps](INFO): Sending 1149 bytes from file Logs/20230512T205743/Express0001.lzma
2023-05-12T21:08:44.756Z,1683925724.756 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0001.lzma.bak
2023-05-12T21:08:44.756Z,1683925724.756 [DataOverHttps](INFO): SBD MOMSN=18301343
2023-05-12T21:09:00.366Z,1683925740.366 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20230512T205743/Express0005.lzma
2023-05-12T21:09:01.368Z,1683925741.368 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0005.lzma.bak
2023-05-12T21:09:01.368Z,1683925741.368 [DataOverHttps](INFO): SBD MOMSN=18301377
2023-05-12T21:09:03.148Z,1683925743.148 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:09:03.149Z,1683925743.149 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:09:03.149Z,1683925743.149 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:09:06.437Z,1683925746.437 [NAL9602](INFO): Powering up NAL9602
2023-05-12T21:09:17.309Z,1683925757.309 [NAL9602](INFO): NAL9602 initialized
2023-05-12T21:09:29.035Z,1683925769.035 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:09:29.035Z,1683925769.035 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+0.0,1489.0,000
2023-05-12T21:09:58.945Z,1683925798.945 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-05-12T21:09:58.946Z,1683925798.946 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:09:58.976Z,1683925798.976 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:09:59.350Z,1683925799.350 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:09:59.350Z,1683925799.350 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-05-12T21:12:04.090Z,1683925924.090 [DVL_micro](ERROR): only read 2 of 4 data items
2023-05-12T21:12:04.090Z,1683925924.090 [DVL_micro](ERROR): Failed to parse:
:BI,-00946,-00871+00000,I
2023-05-12T21:12:59.861Z,1683925979.861 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-05-12T21:12:59.861Z,1683925979.861 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:12:59.872Z,1683925979.872 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:13:00.285Z,1683925980.285 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:13:00.285Z,1683925980.285 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-05-12T21:13:14.262Z,1683925994.262 [CommandExec](IMPORTANT): got command failComponent
2023-05-12T21:13:14.262Z,1683925994.262 [CommandExec](IMPORTANT): Failed components:
2023-05-12T21:13:14.262Z,1683925994.262 [CommandExec](IMPORTANT): No failed Components.
2023-05-12T21:14:03.741Z,1683926043.741 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:14:03.741Z,1683926043.741 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:14:03.741Z,1683926043.741 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:14:03.741Z,1683926043.741 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:14:04.172Z,1683926044.172 [Default:CheckIn:D] Stopped
2023-05-12T21:14:04.172Z,1683926044.172 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:14:04.547Z,1683926044.547 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.975595 min 
2023-05-12T21:14:04.547Z,1683926044.547 [Default:CheckIn:E] Stopped
2023-05-12T21:14:04.548Z,1683926044.548 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:14:04.548Z,1683926044.548 [Default:CheckIn] Stopped
2023-05-12T21:14:04.548Z,1683926044.548 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:14:04.548Z,1683926044.548 [Default:CheckIn](INFO): Running loop #2
2023-05-12T21:14:04.548Z,1683926044.548 [Default:CheckIn] Running Loop=2
2023-05-12T21:14:04.548Z,1683926044.548 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:14:04.548Z,1683926044.548 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:14:44.521Z,1683926084.521 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:14:44.521Z,1683926084.521 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+23.8,0000.0,1489.0,000
2023-05-12T21:16:00.899Z,1683926160.899 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-05-12T21:16:00.899Z,1683926160.899 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:16:00.922Z,1683926160.922 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:16:01.334Z,1683926161.334 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:16:01.334Z,1683926161.334 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-05-12T21:18:23.090Z,1683926303.090 [DAT](INFO): DAT read: Acoustic Wakeup

2023-05-12T21:18:23.090Z,1683926303.090 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2023-05-12T21:18:23.091Z,1683926303.091 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-12T21:18:23.092Z,1683926303.092 [DAT](INFO): commRate: 800
2023-05-12T21:18:23.846Z,1683926303.846 [DAT](INFO): DAT read: Lowpower

2023-05-12T21:18:23.846Z,1683926303.846 [DAT](INFO): unknown deviceResponse_: Lowpower

2023-05-12T21:18:58.627Z,1683926338.627 [DAT](INFO): DAT read: Acoustic Wakeup

2023-05-12T21:18:58.627Z,1683926338.627 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2023-05-12T21:18:58.628Z,1683926338.628 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-12T21:18:58.629Z,1683926338.629 [DAT](INFO): commRate: 800
2023-05-12T21:18:59.634Z,1683926339.634 [DAT](INFO): DAT read: Lowpower

2023-05-12T21:18:59.634Z,1683926339.634 [DAT](INFO): unknown deviceResponse_: Lowpower

2023-05-12T21:19:01.892Z,1683926341.892 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-05-12T21:19:01.892Z,1683926341.892 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:19:01.903Z,1683926341.903 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:19:02.294Z,1683926342.294 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:19:02.294Z,1683926342.294 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-05-12T21:19:04.732Z,1683926344.732 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T21:14:04.5Z
2023-05-12T21:19:04.732Z,1683926344.732 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:19:04.732Z,1683926344.732 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:19:12.976Z,1683926352.976 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230512T205743/Courier0007.lzma
2023-05-12T21:19:13.979Z,1683926353.979 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0007.lzma.bak
2023-05-12T21:19:13.979Z,1683926353.979 [DataOverHttps](INFO): SBD MOMSN=18301403
2023-05-12T21:19:20.075Z,1683926360.075 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-12T21:19:20.075Z,1683926360.075 [NAL9602] Data Fault, FailCount= 2
2023-05-12T21:19:20.075Z,1683926360.075 [NAL9602](ERROR): Data Fault
2023-05-12T21:19:20.145Z,1683926360.145 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-12T21:19:20.479Z,1683926360.479 [NAL9602](INFO): Powering down
2023-05-12T21:19:21.369Z,1683926361.369 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-12T21:19:21.370Z,1683926361.370 [NAL9602] No Fault, FailCount= 2
2023-05-12T21:19:31.085Z,1683926371.085 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20230512T205743/Express0008.lzma
2023-05-12T21:19:32.087Z,1683926372.087 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0008.lzma.bak
2023-05-12T21:19:32.087Z,1683926372.087 [DataOverHttps](INFO): SBD MOMSN=18301405
2023-05-12T21:19:33.828Z,1683926373.828 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:19:33.828Z,1683926373.828 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:19:33.828Z,1683926373.828 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:19:50.783Z,1683926390.783 [NAL9602](INFO): Powering up NAL9602
2023-05-12T21:20:01.688Z,1683926401.688 [NAL9602](INFO): NAL9602 initialized
2023-05-12T21:20:42.798Z,1683926442.798 [DAT](INFO): DAT read: Acoustic Wakeup

2023-05-12T21:20:42.798Z,1683926442.798 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2023-05-12T21:20:42.799Z,1683926442.799 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-12T21:20:42.800Z,1683926442.800 [DAT](INFO): commRate: 800
2023-05-12T21:20:43.806Z,1683926443.806 [DAT](INFO): DAT read: Lowpower

2023-05-12T21:20:43.806Z,1683926443.806 [DAT](INFO): unknown deviceResponse_: Lowpower

2023-05-12T21:22:02.898Z,1683926522.898 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-05-12T21:22:02.898Z,1683926522.898 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:22:02.941Z,1683926522.941 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:22:03.332Z,1683926523.332 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:22:03.332Z,1683926523.332 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-05-12T21:22:37.251Z,1683926557.251 [DVL_micro](ERROR): Failed to parse:
9.99,+99999.99,+9999.99
2023-05-12T21:24:34.432Z,1683926674.432 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:24:34.432Z,1683926674.432 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:24:34.432Z,1683926674.432 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:24:34.432Z,1683926674.432 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:24:34.831Z,1683926674.831 [Default:CheckIn:D] Stopped
2023-05-12T21:24:34.832Z,1683926674.832 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:24:35.228Z,1683926675.228 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.486582 min 
2023-05-12T21:24:35.228Z,1683926675.228 [Default:CheckIn:E] Stopped
2023-05-12T21:24:35.228Z,1683926675.228 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:24:35.228Z,1683926675.228 [Default:CheckIn] Stopped
2023-05-12T21:24:35.229Z,1683926675.229 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:24:35.253Z,1683926675.253 [Default:CheckIn](INFO): Running loop #3
2023-05-12T21:24:35.253Z,1683926675.253 [Default:CheckIn] Running Loop=3
2023-05-12T21:24:35.253Z,1683926675.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:24:35.253Z,1683926675.253 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:25:03.915Z,1683926703.915 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-05-12T21:25:03.915Z,1683926703.915 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:25:03.926Z,1683926703.926 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:25:04.325Z,1683926704.325 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:25:04.325Z,1683926704.325 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-05-12T21:28:04.915Z,1683926884.915 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2023-05-12T21:28:04.915Z,1683926884.915 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:28:04.926Z,1683926884.926 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:28:05.345Z,1683926885.345 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:28:05.359Z,1683926885.359 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2023-05-12T21:29:35.400Z,1683926975.400 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T21:24:35.3Z
2023-05-12T21:29:35.400Z,1683926975.400 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:29:35.400Z,1683926975.400 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:29:41.604Z,1683926981.604 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230512T205743/Courier0010.lzma
2023-05-12T21:29:42.607Z,1683926982.607 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0010.lzma.bak
2023-05-12T21:29:42.607Z,1683926982.607 [DataOverHttps](INFO): SBD MOMSN=18301424
2023-05-12T21:29:58.137Z,1683926998.137 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230512T205743/Express0011.lzma
2023-05-12T21:29:59.139Z,1683926999.139 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0011.lzma.bak
2023-05-12T21:29:59.139Z,1683926999.139 [DataOverHttps](INFO): SBD MOMSN=18301429
2023-05-12T21:30:00.856Z,1683927000.856 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:30:00.856Z,1683927000.856 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:30:00.856Z,1683927000.856 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:30:04.479Z,1683927004.479 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-12T21:30:04.479Z,1683927004.479 [NAL9602] Data Fault, FailCount= 3
2023-05-12T21:30:04.479Z,1683927004.479 [NAL9602](ERROR): Data Fault
2023-05-12T21:30:04.497Z,1683927004.497 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-12T21:30:04.897Z,1683927004.897 [NAL9602](INFO): Powering down
2023-05-12T21:30:05.742Z,1683927005.742 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-12T21:30:05.742Z,1683927005.742 [NAL9602] No Fault, FailCount= 3
2023-05-12T21:30:25.093Z,1683927025.093 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:30:25.094Z,1683927025.094 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+23.9,00000,000
2023-05-12T21:30:35.215Z,1683927035.215 [NAL9602](INFO): Powering up NAL9602
2023-05-12T21:30:46.107Z,1683927046.107 [NAL9602](INFO): NAL9602 initialized
2023-05-12T21:31:05.979Z,1683927065.979 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2023-05-12T21:31:05.979Z,1683927065.979 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:31:05.999Z,1683927065.999 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:31:06.336Z,1683927066.336 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:31:06.336Z,1683927066.336 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2023-05-12T21:34:06.923Z,1683927246.923 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2023-05-12T21:34:06.923Z,1683927246.923 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:34:06.933Z,1683927246.933 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:34:07.332Z,1683927247.332 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:34:07.332Z,1683927247.332 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2023-05-12T21:35:01.460Z,1683927301.460 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:35:01.460Z,1683927301.460 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:35:01.460Z,1683927301.460 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:35:01.460Z,1683927301.460 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:35:01.845Z,1683927301.845 [Default:CheckIn:D] Stopped
2023-05-12T21:35:01.845Z,1683927301.845 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.936802 min 
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn:E] Stopped
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn] Stopped
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn](INFO): Running loop #4
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn] Running Loop=4
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:35:02.262Z,1683927302.262 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:35:40.627Z,1683927340.627 [DVL_micro](ERROR): only read 0 of 4 data items
2023-05-12T21:35:40.627Z,1683927340.627 [DVL_micro](ERROR): Failed to parse:
:BI-01376,+01429,+00000,I
2023-05-12T21:37:07.925Z,1683927427.925 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2023-05-12T21:37:07.925Z,1683927427.925 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:37:07.940Z,1683927427.940 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:37:08.344Z,1683927428.344 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:37:08.344Z,1683927428.344 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2023-05-12T21:37:33.759Z,1683927453.759 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213733.00,A,3648.13946,N,12147.23215,W,2.041,70.00,120523,,,A*4A
2023-05-12T21:37:33.762Z,1683927453.762 [NAL9602](INFO): GPS fix at 20230512T213733: (36.802324, -121.787203)
2023-05-12T21:37:33.774Z,1683927453.774 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:37:33.774Z,1683927453.774 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:37:41.901Z,1683927461.901 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20230512T205743/Courier0013.lzma
2023-05-12T21:37:42.895Z,1683927462.895 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0013.lzma.bak
2023-05-12T21:37:42.895Z,1683927462.895 [DataOverHttps](INFO): SBD MOMSN=18301449
2023-05-12T21:38:00.757Z,1683927480.757 [DataOverHttps](INFO): Sending 284 bytes from file Logs/20230512T205743/Express0014.lzma
2023-05-12T21:38:01.759Z,1683927481.759 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0014.lzma.bak
2023-05-12T21:38:01.759Z,1683927481.759 [DataOverHttps](INFO): SBD MOMSN=18301452
2023-05-12T21:38:05.732Z,1683927485.732 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:38:05.732Z,1683927485.732 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:38:05.732Z,1683927485.732 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:38:06.523Z,1683927486.523 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:43:06.462Z,1683927786.462 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:43:06.462Z,1683927786.462 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:43:06.462Z,1683927786.462 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:43:06.462Z,1683927786.462 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:43:06.860Z,1683927786.860 [Default:CheckIn:D] Stopped
2023-05-12T21:43:06.860Z,1683927786.860 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:43:07.278Z,1683927787.278 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.020390 min 
2023-05-12T21:43:07.278Z,1683927787.278 [Default:CheckIn:E] Stopped
2023-05-12T21:43:07.278Z,1683927787.278 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:43:07.278Z,1683927787.278 [Default:CheckIn] Stopped
2023-05-12T21:43:07.278Z,1683927787.278 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:43:07.279Z,1683927787.279 [Default:CheckIn](INFO): Running loop #5
2023-05-12T21:43:07.279Z,1683927787.279 [Default:CheckIn] Running Loop=5
2023-05-12T21:43:07.279Z,1683927787.279 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:43:07.279Z,1683927787.279 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:43:09.240Z,1683927789.240 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214308.00,A,3648.15207,N,12147.22399,W,0.097,238.80,120523,,,D*77
2023-05-12T21:43:09.243Z,1683927789.243 [NAL9602](INFO): GPS fix at 20230512T214308: (36.802535, -121.787066)
2023-05-12T21:43:09.287Z,1683927789.287 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:43:09.287Z,1683927789.287 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:43:21.128Z,1683927801.128 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230512T205743/Courier0016.lzma
2023-05-12T21:43:22.131Z,1683927802.131 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0016.lzma.bak
2023-05-12T21:43:22.131Z,1683927802.131 [DataOverHttps](INFO): SBD MOMSN=18301463
2023-05-12T21:43:30.681Z,1683927810.681 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:43:30.681Z,1683927810.681 [DVL_micro](ERROR): Failed to parse::TS,00000000000000,35.0,+24.0,0000.0,1489.WI,+03209,-01102,+0000,A
2023-05-12T21:43:37.937Z,1683927817.937 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230512T205743/Express0017.lzma
2023-05-12T21:43:38.939Z,1683927818.939 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0017.lzma.bak
2023-05-12T21:43:38.939Z,1683927818.939 [DataOverHttps](INFO): SBD MOMSN=18301466
2023-05-12T21:43:40.816Z,1683927820.816 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:43:40.817Z,1683927820.817 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:43:40.817Z,1683927820.817 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:43:44.032Z,1683927824.032 [NAL9602](INFO): SBD MO Status=2, MOMSN=16893, MT Status=2, MTMSN=0
2023-05-12T21:43:44.032Z,1683927824.032 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:44:02.232Z,1683927842.232 [NAL9602](INFO): SBD MO Status=0, MOMSN=16893, MT Status=0, MTMSN=0
2023-05-12T21:44:02.232Z,1683927842.232 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:44:32.928Z,1683927872.928 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:48:33.146Z,1683928113.146 [DataOverHttps](IMPORTANT): SBD MTMSN=20230512T214832
2023-05-12T21:48:38.574Z,1683928118.574 [DVL_micro](ERROR): Failed to parse:
9.99,+99999.99,+9999.99
2023-05-12T21:48:41.398Z,1683928121.398 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:48:41.398Z,1683928121.398 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:48:41.398Z,1683928121.398 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:48:41.398Z,1683928121.398 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:48:41.801Z,1683928121.801 [Default:CheckIn:D] Stopped
2023-05-12T21:48:41.801Z,1683928121.801 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:48:42.037Z,1683928122.037 [DataOverHttps](INFO): Received command: ibit
2023-05-12T21:48:42.114Z,1683928122.114 [CommandExec](IMPORTANT): got command ibit
2023-05-12T21:48:42.210Z,1683928122.210 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.602734 min 
2023-05-12T21:48:42.210Z,1683928122.210 [Default:CheckIn:E] Stopped
2023-05-12T21:48:42.210Z,1683928122.210 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:48:42.210Z,1683928122.210 [Default:CheckIn] Stopped
2023-05-12T21:48:42.210Z,1683928122.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:48:42.211Z,1683928122.211 [Default:CheckIn](INFO): Running loop #6
2023-05-12T21:48:42.211Z,1683928122.211 [Default:CheckIn] Running Loop=6
2023-05-12T21:48:42.211Z,1683928122.211 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:48:42.211Z,1683928122.211 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:48:42.219Z,1683928122.219 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-05-12T21:48:42.220Z,1683928122.220 [IBIT](IMPORTANT): Beginning control surface checks.
2023-05-12T21:48:42.223Z,1683928122.223 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-12T21:48:43.829Z,1683928123.829 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214843.00,A,3648.15005,N,12147.22211,W,0.039,130.61,120523,,,D*72
2023-05-12T21:48:43.831Z,1683928123.831 [NAL9602](INFO): GPS fix at 20230512T214843: (36.802501, -121.787035)
2023-05-12T21:48:53.128Z,1683928133.128 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004661
CHAN A1 (24V): -0.002367
CHAN A2 (12V): -0.000698
CHAN A3 (5V): 0.000292
CHAN B0 (3.3V): 0.000377
CHAN B1 (3.15aV): 0.000077
CHAN B2 (3.15bV): 0.000707
CHAN B3 (GND): 0.000714
OPEN: 0.004365
Full Scale: +/- 1 mA
2023-05-12T21:49:28.676Z,1683928168.676 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802502 Longitude: -121.787033
2023-05-12T21:49:29.085Z,1683928169.085 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.343000
2023-05-12T21:49:29.085Z,1683928169.085 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-05-12T21:49:29.086Z,1683928169.086 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-05-12T21:49:29.507Z,1683928169.507 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-05-12T21:49:29.507Z,1683928169.507 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-05-12T21:49:29.508Z,1683928169.508 [IBIT](IMPORTANT): Pressure:9.866451 PSI
2023-05-12T21:49:29.508Z,1683928169.508 [IBIT](IMPORTANT): Humidity:18.593578 %
2023-05-12T21:49:29.889Z,1683928169.889 [IBIT](IMPORTANT): Vehicle Pitch:1.285660 degrees
2023-05-12T21:49:29.889Z,1683928169.889 [IBIT](IMPORTANT): Vehicle  Roll:-10.193114 degrees
2023-05-12T21:49:29.889Z,1683928169.889 [IBIT](IMPORTANT): Vehicle  Heading:200.952026 degrees
2023-05-12T21:49:30.295Z,1683928170.295 [IBIT](IMPORTANT): surfaceThreshold: 1.500000 m
2023-05-12T21:49:30.295Z,1683928170.295 [IBIT](IMPORTANT): buoyancyNeutral: 208.617813 cc
2023-05-12T21:49:30.295Z,1683928170.295 [IBIT](IMPORTANT): massDefault: 2.868872 cm
2023-05-12T21:49:30.296Z,1683928170.296 [IBIT](IMPORTANT): stopDepth: 265.000000 m
2023-05-12T21:49:30.296Z,1683928170.296 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2023-05-12T21:49:30.296Z,1683928170.296 [IBIT](IMPORTANT): IBIT PASSED
2023-05-12T21:49:30.709Z,1683928170.709 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:49:30.709Z,1683928170.709 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:49:35.531Z,1683928175.531 [NAL9602](INFO): SBD MO Status=2, MOMSN=16894, MT Status=2, MTMSN=0
2023-05-12T21:49:35.531Z,1683928175.531 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:49:41.608Z,1683928181.608 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230512T205743/Courier0019.lzma
2023-05-12T21:49:42.611Z,1683928182.611 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0019.lzma.bak
2023-05-12T21:49:42.611Z,1683928182.611 [DataOverHttps](INFO): SBD MOMSN=18301489
2023-05-12T21:49:58.562Z,1683928198.562 [DataOverHttps](INFO): Sending 800 bytes from file Logs/20230512T205743/Express0020.lzma
2023-05-12T21:49:59.563Z,1683928199.563 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0020.lzma.bak
2023-05-12T21:49:59.563Z,1683928199.563 [DataOverHttps](INFO): SBD MOMSN=18301492
2023-05-12T21:50:19.624Z,1683928219.624 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230512T205743/Express0023.lzma
2023-05-12T21:50:20.627Z,1683928220.627 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0023.lzma.bak
2023-05-12T21:50:20.627Z,1683928220.627 [DataOverHttps](INFO): SBD MOMSN=18301518
2023-05-12T21:50:22.458Z,1683928222.458 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:50:22.458Z,1683928222.458 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:50:22.458Z,1683928222.458 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:50:23.688Z,1683928223.688 [NAL9602](INFO): SBD MO Status=0, MOMSN=16894, MT Status=0, MTMSN=0
2023-05-12T21:50:23.688Z,1683928223.688 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:50:54.387Z,1683928254.387 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:51:06.099Z,1683928266.099 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:51:06.100Z,1683928266.100 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+24.1,000.0,000
2023-05-12T21:53:36.395Z,1683928416.395 [DVL_micro](ERROR): only read 2 of 4 data items
2023-05-12T21:53:36.395Z,1683928416.395 [DVL_micro](ERROR): Failed to parse:
:BI,01178,+0000,I
2023-05-12T21:55:23.115Z,1683928523.115 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:55:23.115Z,1683928523.115 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:55:23.115Z,1683928523.115 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:55:23.115Z,1683928523.115 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:55:23.520Z,1683928523.520 [Default:CheckIn:D] Stopped
2023-05-12T21:55:23.520Z,1683928523.520 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:55:23.915Z,1683928523.915 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.298059 min 
2023-05-12T21:55:23.915Z,1683928523.915 [Default:CheckIn:E] Stopped
2023-05-12T21:55:23.915Z,1683928523.915 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:55:23.915Z,1683928523.915 [Default:CheckIn] Stopped
2023-05-12T21:55:23.915Z,1683928523.915 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:55:23.916Z,1683928523.916 [Default:CheckIn](INFO): Running loop #7
2023-05-12T21:55:23.916Z,1683928523.916 [Default:CheckIn] Running Loop=7
2023-05-12T21:55:23.916Z,1683928523.916 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:55:23.916Z,1683928523.916 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:55:25.931Z,1683928525.931 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215525.00,A,3648.44710,N,12147.10872,W,6.026,359.51,120523,,,D*71
2023-05-12T21:55:25.934Z,1683928525.934 [NAL9602](INFO): GPS fix at 20230512T215525: (36.807452, -121.785145)
2023-05-12T21:55:25.945Z,1683928525.945 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:55:25.946Z,1683928525.946 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:55:33.828Z,1683928533.828 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230512T205743/Courier0025.lzma
2023-05-12T21:55:34.831Z,1683928534.831 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0025.lzma.bak
2023-05-12T21:55:34.831Z,1683928534.831 [DataOverHttps](INFO): SBD MOMSN=18301556
2023-05-12T21:55:50.597Z,1683928550.597 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230512T205743/Express0026.lzma
2023-05-12T21:55:50.972Z,1683928550.972 [NAL9602](INFO): SBD MO Status=0, MOMSN=16895, MT Status=0, MTMSN=0
2023-05-12T21:55:50.972Z,1683928550.972 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:55:51.599Z,1683928551.599 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0026.lzma.bak
2023-05-12T21:55:51.599Z,1683928551.599 [DataOverHttps](INFO): SBD MOMSN=18301559
2023-05-12T21:55:53.408Z,1683928553.408 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:55:53.408Z,1683928553.408 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:55:53.408Z,1683928553.408 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:56:06.365Z,1683928566.365 [DVL_micro](ERROR): only read 3 of 4 data items
2023-05-12T21:56:06.365Z,1683928566.365 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.999
2023-05-12T21:56:21.681Z,1683928581.681 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:58:39.101Z,1683928719.101 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:58:39.101Z,1683928719.101 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+24.0,0000.0,1489.0I,+01035,-01049,+01611,+00000,A
2023-05-12T22:00:54.106Z,1683928854.106 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T22:00:54.106Z,1683928854.106 [Default:CheckIn:C.Wait] Stopped
2023-05-12T22:00:54.106Z,1683928854.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T22:00:54.106Z,1683928854.106 [Default:CheckIn:D] Running Loop=1
2023-05-12T22:00:54.505Z,1683928854.505 [Default:CheckIn:D] Stopped
2023-05-12T22:00:54.505Z,1683928854.505 [Default:CheckIn:E] Running Loop=1
2023-05-12T22:00:54.910Z,1683928854.910 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.814473 min 
2023-05-12T22:00:54.910Z,1683928854.910 [Default:CheckIn:E] Stopped
2023-05-12T22:00:54.911Z,1683928854.911 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T22:00:54.911Z,1683928854.911 [Default:CheckIn] Stopped
2023-05-12T22:00:54.911Z,1683928854.911 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T22:00:54.911Z,1683928854.911 [Default:CheckIn](INFO): Running loop #8
2023-05-12T22:00:54.911Z,1683928854.911 [Default:CheckIn] Running Loop=8
2023-05-12T22:00:54.911Z,1683928854.911 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T22:00:54.911Z,1683928854.911 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T22:00:56.915Z,1683928856.915 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220056.00,A,3648.37106,N,12147.71991,W,8.961,279.58,120523,,,D*76
2023-05-12T22:00:56.917Z,1683928856.917 [NAL9602](INFO): GPS fix at 20230512T220056: (36.806184, -121.795332)
2023-05-12T22:00:56.929Z,1683928856.929 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T22:00:56.929Z,1683928856.929 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T22:01:01.828Z,1683928861.828 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T22:01:01.829Z,1683928861.829 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+24.0,0000.0,1489.0,000
2023-05-12T22:01:03.864Z,1683928863.864 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230512T205743/Courier0028.lzma
2023-05-12T22:01:04.867Z,1683928864.867 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Courier0028.lzma.bak
2023-05-12T22:01:04.867Z,1683928864.867 [DataOverHttps](INFO): SBD MOMSN=18301578
2023-05-12T22:01:05.460Z,1683928865.460 [NAL9602](INFO): SBD MO Status=0, MOMSN=16896, MT Status=0, MTMSN=0
2023-05-12T22:01:05.460Z,1683928865.460 [NAL9602](INFO): No messages in MT queue
2023-05-12T22:01:26.313Z,1683928886.313 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230512T205743/Express0029.lzma
2023-05-12T22:01:27.316Z,1683928887.316 [DataOverHttps](INFO): Moved sent file to Logs/20230512T205743/Express0029.lzma.bak
2023-05-12T22:01:27.316Z,1683928887.316 [DataOverHttps](IMPORTANT): SBD MOMSN=18301582, MTMSN=20230512T220126
2023-05-12T22:01:29.396Z,1683928889.396 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T22:01:29.396Z,1683928889.396 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T22:01:29.396Z,1683928889.396 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T22:01:34.737Z,1683928894.737 [DataOverHttps](INFO): Received command: configSet DAT.loadAtStartup 0 bool persist;configSet DATMMP.loadAtStartup 1 bool persist;configSet DATMMP.simulateHardware 0 bool persist;restart app
2023-05-12T22:01:35.336Z,1683928895.336 [CommandExec](IMPORTANT): got command configSet DAT.loadAtStartup 0 bool persist
2023-05-12T22:01:35.336Z,1683928895.336 [CommandExec](IMPORTANT): configSet DAT.loadAtStartup requires a restart to take effect.
2023-05-12T22:01:35.340Z,1683928895.340 [CommandExec](IMPORTANT): got command configSet DATMMP.loadAtStartup 1 bool persist
2023-05-12T22:01:35.340Z,1683928895.340 [CommandExec](IMPORTANT): configSet DATMMP.loadAtStartup requires a restart to take effect.
2023-05-12T22:01:35.343Z,1683928895.343 [CommandExec](IMPORTANT): got command configSet DATMMP.simulateHardware 0 bool persist
2023-05-12T22:01:35.345Z,1683928895.345 [CommandExec](IMPORTANT): got command restart application
2023-05-12T22:01:36.231Z,1683928896.231 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T22:01:36.349Z,1683928896.349 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-05-12T22:01:36.349Z,1683928896.349 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:36.349Z,1683928896.349 [CommandExec](INFO): Uninitializing the command executive.
2023-05-12T22:01:36.350Z,1683928896.350 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-12T22:01:36.350Z,1683928896.350 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.449Z,1683928896.449 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-05-12T22:01:36.449Z,1683928896.449 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-12T22:01:36.449Z,1683928896.449 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.450Z,1683928896.450 [NavChartDb](INFO): Join timeout helper Thread ID is 1291
2023-05-12T22:01:36.474Z,1683928896.474 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:36.475Z,1683928896.475 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.489Z,1683928896.489 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-12T22:01:36.489Z,1683928896.489 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.490Z,1683928896.490 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1292
2023-05-12T22:01:36.841Z,1683928896.841 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:36.841Z,1683928896.841 [WetLabsBB2FL](INFO): Powering down
2023-05-12T22:01:36.842Z,1683928896.842 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.849Z,1683928896.849 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-12T22:01:36.849Z,1683928896.849 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.849Z,1683928896.849 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1293
2023-05-12T22:01:37.533Z,1683928897.533 [CTD_Seabird](INFO): Powering down
2023-05-12T22:01:37.548Z,1683928897.548 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:37.548Z,1683928897.548 [CTD_Seabird](INFO): Powering down
2023-05-12T22:01:37.561Z,1683928897.561 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.569Z,1683928897.569 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-12T22:01:37.569Z,1683928897.569 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.570Z,1683928897.570 [Radio_Surface](INFO): Join timeout helper Thread ID is 1294
2023-05-12T22:01:37.957Z,1683928897.957 [Radio_Surface](INFO): Powering down
2023-05-12T22:01:37.958Z,1683928897.958 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:37.958Z,1683928897.958 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.977Z,1683928897.977 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-12T22:01:37.977Z,1683928897.977 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.978Z,1683928897.978 [Onboard](INFO): Join timeout helper Thread ID is 1295
2023-05-12T22:01:41.577Z,1683928901.577 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:41.577Z,1683928901.577 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:41.594Z,1683928901.594 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-12T22:01:41.594Z,1683928901.594 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:41.594Z,1683928901.594 [DataOverHttps](INFO): Join timeout helper Thread ID is 1296
2023-05-12T22:01:42.020Z,1683928902.020 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:42.023Z,1683928902.023 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.042Z,1683928902.042 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-05-12T22:01:42.042Z,1683928902.042 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.042Z,1683928902.042 [DAT](INFO): Join timeout helper Thread ID is 1297
2023-05-12T22:01:42.234Z,1683928902.234 [DAT](INFO): Powering down
2023-05-12T22:01:42.317Z,1683928902.317 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:42.318Z,1683928902.318 [DAT](INFO): Powering down
2023-05-12T22:01:42.318Z,1683928902.318 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.330Z,1683928902.330 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-12T22:01:42.330Z,1683928902.330 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.330Z,1683928902.330 [BackseatComponent](INFO): Join timeout helper Thread ID is 1298
2023-05-12T22:01:42.473Z,1683928902.473 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:42.473Z,1683928902.473 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.483Z,1683928902.483 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-12T22:01:42.483Z,1683928902.483 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.484Z,1683928902.484 [logger](INFO): Join timeout helper Thread ID is 1299
2023-05-12T22:01:42.485Z,1683928902.485 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:42.485Z,1683928902.485 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.502Z,1683928902.502 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-12T22:01:42.502Z,1683928902.502 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.502Z,1683928902.502 [CommandLine](INFO): Join timeout helper Thread ID is 1300
2023-05-12T22:01:42.597Z,1683928902.597 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:42.597Z,1683928902.597 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.602Z,1683928902.602 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-12T22:01:42.602Z,1683928902.602 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.602Z,1683928902.602 [CommandExec](INFO): Join timeout helper Thread ID is 1301
2023-05-12T22:01:42.603Z,1683928902.603 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-12T22:01:42.603Z,1683928902.603 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.604Z,1683928902.604 [controlThread](INFO): Join timeout helper Thread ID is 1302
2023-05-12T22:01:42.677Z,1683928902.677 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:42.677Z,1683928902.677 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-12T22:01:42.678Z,1683928902.678 [AHRS_M2](INFO): Powering down
2023-05-12T22:01:42.821Z,1683928902.821 [DVL_micro](INFO): Powering down
2023-05-12T22:01:42.822Z,1683928902.822 [NAL9602](INFO): Powering down
2023-05-12T22:01:42.825Z,1683928902.825 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-12T22:01:42.826Z,1683928902.826 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-12T22:01:42.827Z,1683928902.827 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-12T22:01:42.827Z,1683928902.827 [MissionManager](INFO): Uninitializing Mission Default
2023-05-12T22:01:42.827Z,1683928902.827 [Default] Stopped
2023-05-12T22:01:42.827Z,1683928902.827 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-12T22:01:42.827Z,1683928902.827 [Default:B.GoToSurface] Stopped
2023-05-12T22:01:42.827Z,1683928902.827 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-12T22:01:42.828Z,1683928902.828 [Default:CheckIn] Stopped
2023-05-12T22:01:42.828Z,1683928902.828 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T22:01:42.828Z,1683928902.828 [Default:CheckIn:C.Wait] Stopped
2023-05-12T22:01:42.828Z,1683928902.828 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T22:01:42.831Z,1683928902.831 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-12T22:01:42.831Z,1683928902.831 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-12T22:01:42.831Z,1683928902.831 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-12T22:01:42.831Z,1683928902.831 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-12T22:01:42.832Z,1683928902.832 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-12T22:01:42.832Z,1683928902.832 [BuoyancyServo](INFO): Powering down
2023-05-12T22:01:42.845Z,1683928902.845 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-12T22:01:42.845Z,1683928902.845 [ElevatorServo](INFO): Powering down
2023-05-12T22:01:42.846Z,1683928902.846 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-12T22:01:42.846Z,1683928902.846 [MassServo](INFO): Powering down
2023-05-12T22:01:42.847Z,1683928902.847 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-12T22:01:42.847Z,1683928902.847 [RudderServo](INFO): Powering down
2023-05-12T22:01:42.848Z,1683928902.848 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-12T22:01:42.848Z,1683928902.848 [ThrusterHE](INFO): Powering down
2023-05-12T22:01:42.849Z,1683928902.849 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-12T22:01:42.849Z,1683928902.849 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-12T22:01:42.850Z,1683928902.850 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-12T22:01:42.850Z,1683928902.850 [CBIT](DEBUG): Powering off loads.
2023-05-12T22:01:42.861Z,1683928902.861 [CBIT](DEBUG): Disabling WDT.
2023-05-12T22:01:42.873Z,1683928902.873 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-12T22:01:42.874Z,1683928902.874 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.918Z,1683928902.918 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.921Z,1683928902.921 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.928Z,1683928902.928 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.935Z,1683928902.935 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:42.976Z,1683928902.976 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:43.029Z,1683928903.029 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:43.034Z,1683928903.034 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:43.056Z,1683928903.056 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:43.125Z,1683928903.125 [logger ThreadHandler](INFO): Thread cancelled.