2025-03-05T20:25:58.599Z,1741206358.599 [Supervisor](DEBUG): Initializing supervisor.
2025-03-05T20:25:58.603Z,1741206358.603 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-03-05T20:25:58.604Z,1741206358.604 [SyncHandler](INFO): Protected caller Thread ID is 8183
2025-03-05T20:25:58.604Z,1741206358.604 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-03-05T20:25:58.605Z,1741206358.605 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-03-05T20:25:58.606Z,1741206358.606 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8184
2025-03-05T20:25:58.609Z,1741206358.609 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-03-05T20:25:58.626Z,1741206358.626 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-03-05T20:25:58.627Z,1741206358.627 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-03-05T20:25:58.628Z,1741206358.628 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8185
2025-03-05T20:25:58.632Z,1741206358.632 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-03-05T20:25:58.633Z,1741206358.633 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-03-05T20:25:58.633Z,1741206358.633 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8186
2025-03-05T20:25:58.635Z,1741206358.635 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-03-05T20:25:58.636Z,1741206358.636 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-03-05T20:25:58.637Z,1741206358.637 [logger ThreadHandler](INFO): Protected caller Thread ID is 8187
2025-03-05T20:25:58.640Z,1741206358.640 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-03-05T20:25:58.640Z,1741206358.640 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-03-05T20:25:58.642Z,1741206358.642 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-03-05T20:25:58.753Z,1741206358.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-03-05T20:25:58.754Z,1741206358.754 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-03-05T20:25:59.006Z,1741206359.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-03-05T20:25:59.006Z,1741206359.006 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-03-05T20:25:59.289Z,1741206359.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-03-05T20:25:59.290Z,1741206359.290 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-03-05T20:25:59.412Z,1741206359.412 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-03-05T20:25:59.413Z,1741206359.413 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-03-05T20:26:00.199Z,1741206360.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-03-05T20:26:00.199Z,1741206360.199 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-03-05T20:26:00.729Z,1741206360.729 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-03-05T20:26:00.730Z,1741206360.730 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-03-05T20:26:01.361Z,1741206361.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-03-05T20:26:01.362Z,1741206361.362 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-03-05T20:26:02.097Z,1741206362.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-03-05T20:26:02.098Z,1741206362.098 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-03-05T20:26:02.462Z,1741206362.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-03-05T20:26:02.462Z,1741206362.462 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-03-05T20:26:02.866Z,1741206362.866 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-03-05T20:26:02.866Z,1741206362.866 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-03-05T20:26:03.114Z,1741206363.114 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-03-05T20:26:03.114Z,1741206363.114 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-03-05T20:26:03.268Z,1741206363.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-03-05T20:26:03.268Z,1741206363.268 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-03-05T20:26:03.363Z,1741206363.363 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-03-05T20:26:03.455Z,1741206363.455 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-03-05T20:26:03.659Z,1741206363.659 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-03-05T20:26:03.660Z,1741206363.660 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-03-05T20:26:03.909Z,1741206363.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-03-05T20:26:03.911Z,1741206363.911 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-03-05T20:26:03.912Z,1741206363.912 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-03-05T20:26:04.009Z,1741206364.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-03-05T20:26:04.282Z,1741206364.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-03-05T20:26:04.282Z,1741206364.282 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-03-05T20:26:04.390Z,1741206364.390 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-03-05T20:26:04.572Z,1741206364.572 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-03-05T20:26:04.685Z,1741206364.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-03-05T20:26:04.810Z,1741206364.810 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-03-05T20:26:04.937Z,1741206364.937 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-03-05T20:26:05.058Z,1741206365.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-03-05T20:26:05.236Z,1741206365.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-03-05T20:26:05.346Z,1741206365.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-03-05T20:26:05.444Z,1741206365.444 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-03-05T20:26:05.555Z,1741206365.555 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-03-05T20:26:05.665Z,1741206365.665 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2025-03-05T20:26:05.666Z,1741206365.666 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-03-05T20:26:05.673Z,1741206365.673 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-03-05T20:26:05.841Z,1741206365.841 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-03-05T20:26:05.842Z,1741206365.842 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-03-05T20:26:05.997Z,1741206365.997 [BuoyancyServo] Loaded
2025-03-05T20:26:05.997Z,1741206365.997 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-03-05T20:26:06.020Z,1741206366.020 [ElevatorServo] Loaded
2025-03-05T20:26:06.020Z,1741206366.020 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-03-05T20:26:06.042Z,1741206366.042 [MassServo] Loaded
2025-03-05T20:26:06.042Z,1741206366.042 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-03-05T20:26:06.063Z,1741206366.063 [RudderServo] Loaded
2025-03-05T20:26:06.063Z,1741206366.063 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-03-05T20:26:06.080Z,1741206366.080 [ThrusterHE] Loaded
2025-03-05T20:26:06.081Z,1741206366.081 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-03-05T20:26:06.081Z,1741206366.081 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-03-05T20:26:06.081Z,1741206366.081 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-03-05T20:26:06.216Z,1741206366.216 [SBIT](DEBUG): Construct Startup Built In Test.
2025-03-05T20:26:06.230Z,1741206366.230 [SBIT] Loaded
2025-03-05T20:26:06.230Z,1741206366.230 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-03-05T20:26:06.233Z,1741206366.233 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-03-05T20:26:06.253Z,1741206366.253 [IBIT] Loaded
2025-03-05T20:26:06.254Z,1741206366.254 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-03-05T20:26:06.259Z,1741206366.259 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-03-05T20:26:06.474Z,1741206366.474 [CBIT] Loaded
2025-03-05T20:26:06.474Z,1741206366.474 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-03-05T20:26:06.474Z,1741206366.474 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-03-05T20:26:06.475Z,1741206366.475 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-03-05T20:26:07.026Z,1741206367.026 [CTD_Seabird] Loaded
2025-03-05T20:26:07.026Z,1741206367.026 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-03-05T20:26:07.027Z,1741206367.027 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406784E0
2025-03-05T20:26:07.027Z,1741206367.027 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8275
2025-03-05T20:26:07.104Z,1741206367.104 [ESPComponent] Loaded
2025-03-05T20:26:07.105Z,1741206367.105 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-03-05T20:26:07.125Z,1741206367.125 [PAR_Licor] Loaded
2025-03-05T20:26:07.126Z,1741206367.126 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-03-05T20:26:07.235Z,1741206367.235 [WetLabsBB2FL] Loaded
2025-03-05T20:26:07.236Z,1741206367.236 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-03-05T20:26:07.237Z,1741206367.237 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406A84E0
2025-03-05T20:26:07.237Z,1741206367.237 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8276
2025-03-05T20:26:07.238Z,1741206367.238 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-03-05T20:26:07.238Z,1741206367.238 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-03-05T20:26:07.318Z,1741206367.318 [DepthRateCalculator] Loaded
2025-03-05T20:26:07.318Z,1741206367.318 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-03-05T20:26:07.323Z,1741206367.323 [PitchRateCalculator] Loaded
2025-03-05T20:26:07.323Z,1741206367.323 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-03-05T20:26:07.396Z,1741206367.396 [SpeedCalculator] Loaded
2025-03-05T20:26:07.398Z,1741206367.398 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-03-05T20:26:07.402Z,1741206367.402 [YawRateCalculator] Loaded
2025-03-05T20:26:07.403Z,1741206367.403 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-03-05T20:26:07.422Z,1741206367.422 [ElevatorOffsetCalculator] Loaded
2025-03-05T20:26:07.422Z,1741206367.422 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-03-05T20:26:07.422Z,1741206367.422 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-03-05T20:26:07.423Z,1741206367.423 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-03-05T20:26:07.538Z,1741206367.538 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-03-05T20:26:07.539Z,1741206367.539 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-03-05T20:26:07.565Z,1741206367.565 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-03-05T20:26:07.565Z,1741206367.565 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-03-05T20:26:07.673Z,1741206367.673 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-03-05T20:26:07.674Z,1741206367.674 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-03-05T20:26:07.687Z,1741206367.687 [NavChart] Loaded
2025-03-05T20:26:07.687Z,1741206367.687 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-03-05T20:26:07.693Z,1741206367.693 [UniversalFixResidualReporter] Loaded
2025-03-05T20:26:07.693Z,1741206367.693 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-03-05T20:26:07.694Z,1741206367.694 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-03-05T20:26:07.694Z,1741206367.694 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-03-05T20:26:08.137Z,1741206368.137 [AHRS_M2] Loaded
2025-03-05T20:26:08.138Z,1741206368.138 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-03-05T20:26:08.175Z,1741206368.175 [BackseatComponent] Loaded
2025-03-05T20:26:08.175Z,1741206368.175 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-03-05T20:26:08.176Z,1741206368.176 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A694E0
2025-03-05T20:26:08.177Z,1741206368.177 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 8277
2025-03-05T20:26:08.180Z,1741206368.180 [LcmUniversalReporter] Loaded
2025-03-05T20:26:08.180Z,1741206368.180 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-03-05T20:26:08.908Z,1741206368.908 [BPC1] Loaded
2025-03-05T20:26:08.909Z,1741206368.909 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-03-05T20:26:08.998Z,1741206368.998 [DATMMP] Loaded
2025-03-05T20:26:08.998Z,1741206368.998 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2025-03-05T20:26:08.999Z,1741206368.999 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 40A9A4E0
2025-03-05T20:26:08.999Z,1741206368.999 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 8278
2025-03-05T20:26:09.069Z,1741206369.069 [DataOverHttps] Loaded
2025-03-05T20:26:09.069Z,1741206369.069 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-03-05T20:26:09.070Z,1741206369.070 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40ACA4E0
2025-03-05T20:26:09.071Z,1741206369.071 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8279
2025-03-05T20:26:09.094Z,1741206369.094 [Depth_Keller] Loaded
2025-03-05T20:26:09.094Z,1741206369.094 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-03-05T20:26:09.099Z,1741206369.099 [DropWeight] Loaded
2025-03-05T20:26:09.099Z,1741206369.099 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-03-05T20:26:09.139Z,1741206369.139 [DVL_micro] Loaded
2025-03-05T20:26:09.140Z,1741206369.140 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2025-03-05T20:26:09.200Z,1741206369.200 [NAL9602] Loaded
2025-03-05T20:26:09.200Z,1741206369.200 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-03-05T20:26:09.225Z,1741206369.225 [Onboard] Loaded
2025-03-05T20:26:09.226Z,1741206369.226 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-03-05T20:26:09.227Z,1741206369.227 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AFA4E0
2025-03-05T20:26:09.227Z,1741206369.227 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 8280
2025-03-05T20:26:09.241Z,1741206369.241 [Power24vConverter] Loaded
2025-03-05T20:26:09.241Z,1741206369.241 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-03-05T20:26:09.256Z,1741206369.256 [Radio_Surface] Loaded
2025-03-05T20:26:09.257Z,1741206369.257 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-03-05T20:26:09.258Z,1741206369.258 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B2A4E0
2025-03-05T20:26:09.258Z,1741206369.258 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8281
2025-03-05T20:26:09.273Z,1741206369.273 [Sonardyne_Nano] Loaded
2025-03-05T20:26:09.274Z,1741206369.274 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-03-05T20:26:09.274Z,1741206369.274 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-03-05T20:26:09.275Z,1741206369.275 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-03-05T20:26:09.342Z,1741206369.342 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-03-05T20:26:09.342Z,1741206369.342 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-03-05T20:26:09.392Z,1741206369.392 [VerticalControl](DEBUG): Construct VerticalControl.
2025-03-05T20:26:09.441Z,1741206369.441 [VerticalControl] Loaded
2025-03-05T20:26:09.442Z,1741206369.442 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-03-05T20:26:09.445Z,1741206369.445 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-03-05T20:26:09.487Z,1741206369.487 [HorizontalControl] Loaded
2025-03-05T20:26:09.487Z,1741206369.487 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-03-05T20:26:09.490Z,1741206369.490 [SpeedControl](DEBUG): Construct SpeedControl.
2025-03-05T20:26:09.491Z,1741206369.491 [SpeedControl] Loaded
2025-03-05T20:26:09.492Z,1741206369.492 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-03-05T20:26:09.494Z,1741206369.494 [LoopControl](DEBUG): Construct LoopControl.
2025-03-05T20:26:09.495Z,1741206369.495 [LoopControl] Loaded
2025-03-05T20:26:09.495Z,1741206369.495 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-03-05T20:26:09.496Z,1741206369.496 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-03-05T20:26:09.496Z,1741206369.496 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-03-05T20:26:09.506Z,1741206369.506 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-03-05T20:26:09.507Z,1741206369.507 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-03-05T20:26:09.832Z,1741206369.832 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-03-05T20:26:09.838Z,1741206369.838 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-03-05T20:26:09.841Z,1741206369.841 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-03-05T20:26:09.853Z,1741206369.853 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-03-05T20:26:09.854Z,1741206369.854 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C524E0
2025-03-05T20:26:09.854Z,1741206369.854 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8282
2025-03-05T20:26:09.858Z,1741206369.858 [Supervisor](INFO): Main Thread ID is 7991
2025-03-05T20:26:09.858Z,1741206369.858 [Supervisor](DEBUG): Running supervisor.
2025-03-05T20:26:09.859Z,1741206369.859 [CommandExec ThreadHandler](INFO): Handler Thread ID is 8283
2025-03-05T20:26:09.860Z,1741206369.860 [CommandExec](INFO): Initializing the command executive.
2025-03-05T20:26:09.861Z,1741206369.861 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8284
2025-03-05T20:26:09.864Z,1741206369.864 [controlThread ThreadHandler](INFO): Handler Thread ID is 8285
2025-03-05T20:26:09.864Z,1741206369.864 [controlThread](DEBUG): Initializing ControlThread
2025-03-05T20:26:09.866Z,1741206369.866 [SBIT](INFO): Initialize SBIT Component.
2025-03-05T20:26:09.867Z,1741206369.867 [SBIT](IMPORTANT): git: 2024-09-17
2025-03-05T20:26:09.867Z,1741206369.867 [SBIT](INFO): git hash: 40e9ce87bff78b617219447905233bfcf6062b37
2025-03-05T20:26:09.867Z,1741206369.867 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-03-05T20:26:09.869Z,1741206369.869 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-03-05T20:26:09.870Z,1741206369.870 [SBIT](INFO): Beginning SBIT in 68.000000 seconds.
2025-03-05T20:26:09.870Z,1741206369.870 [IBIT](INFO): Initialize IBIT Component.
2025-03-05T20:26:09.871Z,1741206369.871 [CBIT](DEBUG): Initialize CBIT Component.
2025-03-05T20:26:09.872Z,1741206369.872 [logger ThreadHandler](INFO): Handler Thread ID is 8286
2025-03-05T20:26:09.884Z,1741206369.884 [CBIT](DEBUG): Initialized mux pins.
2025-03-05T20:26:09.884Z,1741206369.884 [CBIT](DEBUG): Initializing the watchdog timer.
2025-03-05T20:26:09.892Z,1741206369.892 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8287
2025-03-05T20:26:09.893Z,1741206369.893 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-03-05T20:26:09.897Z,1741206369.897 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8289
2025-03-05T20:26:09.900Z,1741206369.900 [WetLabsBB2FL](INFO): Powering up
2025-03-05T20:26:09.901Z,1741206369.901 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 8291
2025-03-05T20:26:09.908Z,1741206369.908 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-03-05T20:26:09.908Z,1741206369.908 [CBIT](DEBUG): Initializing heartbeat.
2025-03-05T20:26:09.909Z,1741206369.909 [DATMMP ThreadHandler](INFO): Handler Thread ID is 8292
2025-03-05T20:26:09.910Z,1741206369.910 [DATMMP](INFO): Start
2025-03-05T20:26:09.910Z,1741206369.910 [DATMMP](INFO): Powering up
2025-03-05T20:26:09.910Z,1741206369.910 [DATMMP](DEBUG): Initializing DATMMP.
2025-03-05T20:26:09.913Z,1741206369.913 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8294
2025-03-05T20:26:09.914Z,1741206369.914 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-03-05T20:26:09.936Z,1741206369.936 [Onboard ThreadHandler](INFO): Handler Thread ID is 8295
2025-03-05T20:26:09.953Z,1741206369.953 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8296
2025-03-05T20:26:09.973Z,1741206369.973 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8297
2025-03-05T20:26:09.975Z,1741206369.975 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-03-05T20:26:09.975Z,1741206369.975 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-03-05T20:26:09.976Z,1741206369.976 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-03-05T20:26:09.976Z,1741206369.976 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-03-05T20:26:09.976Z,1741206369.976 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-03-05T20:26:09.976Z,1741206369.976 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-03-05T20:26:09.976Z,1741206369.976 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-03-05T20:26:09.976Z,1741206369.976 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-03-05T20:26:09.980Z,1741206369.980 [CBIT](DEBUG): Deactivating GF circuits.
2025-03-05T20:26:09.980Z,1741206369.980 [CBIT](DEBUG): Deactivating emergency mode.
2025-03-05T20:26:10.020Z,1741206370.020 [CBIT](DEBUG): Backplane powered.
2025-03-05T20:26:10.024Z,1741206370.024 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-03-05T20:26:10.025Z,1741206370.025 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-03-05T20:26:10.025Z,1741206370.025 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-03-05T20:26:10.025Z,1741206370.025 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-03-05T20:26:10.025Z,1741206370.025 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-03-05T20:26:10.027Z,1741206370.027 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-03-05T20:26:10.027Z,1741206370.027 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-03-05T20:26:10.034Z,1741206370.034 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-03-05T20:26:10.044Z,1741206370.044 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-03-05T20:26:10.044Z,1741206370.044 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-03-05T20:26:10.045Z,1741206370.045 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-03-05T20:26:10.046Z,1741206370.046 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-03-05T20:26:10.046Z,1741206370.046 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-03-05T20:26:10.047Z,1741206370.047 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-03-05T20:26:10.056Z,1741206370.056 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-03-05T20:26:10.120Z,1741206370.120 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-03-05T20:26:10.153Z,1741206370.153 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-05T20:26:10.164Z,1741206370.164 [DATMMP](INFO): Starting
2025-03-05T20:26:10.186Z,1741206370.186 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-03-05T20:26:10.186Z,1741206370.186 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-03-05T20:26:10.186Z,1741206370.186 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-03-05T20:26:10.187Z,1741206370.187 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-03-05T20:26:10.360Z,1741206370.360 [Radio_Surface](INFO): Powering up
2025-03-05T20:26:10.416Z,1741206370.416 [DATMMP](INFO): Starting
2025-03-05T20:26:10.525Z,1741206370.525 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-03-05T20:26:10.546Z,1741206370.546 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-03-05T20:26:10.547Z,1741206370.547 [Default:A.Wait](DEBUG): Construct Wait.
2025-03-05T20:26:10.550Z,1741206370.550 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-05T20:26:10.591Z,1741206370.591 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-05T20:26:10.593Z,1741206370.593 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-05T20:26:10.615Z,1741206370.615 [Default:E.Execute](DEBUG): Construct Execute.
2025-03-05T20:26:10.618Z,1741206370.618 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-03-05T20:26:10.632Z,1741206370.632 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-05T20:26:10.646Z,1741206370.646 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-03-05T20:26:10.668Z,1741206370.668 [DATMMP](INFO): Starting
2025-03-05T20:26:10.713Z,1741206370.713 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.444336 decibar, 0.000000 m
2025-03-05T20:26:10.717Z,1741206370.717 [Power24vConverter](INFO): Powering up.
2025-03-05T20:26:10.718Z,1741206370.718 [Sonardyne_Nano](INFO): Initializing.
2025-03-05T20:26:10.744Z,1741206370.744 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-03-05T20:26:10.775Z,1741206370.775 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-03-05T20:26:10.780Z,1741206370.780 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-03-05T20:26:10.781Z,1741206370.781 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-03-05T20:26:10.788Z,1741206370.788 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-03-05T20:26:10.789Z,1741206370.789 [MassServo](DEBUG): Initializing EZServoServo.
2025-03-05T20:26:10.796Z,1741206370.796 [MassServo](DEBUG): Initializing MassServo.
2025-03-05T20:26:10.797Z,1741206370.797 [RudderServo](DEBUG): Initializing EZServoServo.
2025-03-05T20:26:10.804Z,1741206370.804 [RudderServo](DEBUG): Initializing RudderServo.
2025-03-05T20:26:10.805Z,1741206370.805 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-03-05T20:26:10.812Z,1741206370.812 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-03-05T20:26:10.920Z,1741206370.920 [DATMMP](INFO): Starting
2025-03-05T20:26:11.172Z,1741206371.172 [DATMMP](INFO): Starting
2025-03-05T20:26:11.424Z,1741206371.424 [DATMMP](INFO): Starting
2025-03-05T20:26:11.676Z,1741206371.676 [DATMMP](INFO): Starting
2025-03-05T20:26:11.928Z,1741206371.928 [DATMMP](INFO): Starting
2025-03-05T20:26:12.180Z,1741206372.180 [DATMMP](INFO): Starting
2025-03-05T20:26:12.432Z,1741206372.432 [DATMMP](INFO): Starting
2025-03-05T20:26:12.512Z,1741206372.512 [WetLabsBB2FL](INFO): Powering down
2025-03-05T20:26:12.666Z,1741206372.666 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-03-05T20:26:12.684Z,1741206372.684 [DATMMP](INFO): Starting
2025-03-05T20:26:12.936Z,1741206372.936 [DATMMP](INFO): Starting
2025-03-05T20:26:13.188Z,1741206373.188 [DATMMP](INFO): Starting
2025-03-05T20:26:13.440Z,1741206373.440 [DATMMP](INFO): Starting
2025-03-05T20:26:13.692Z,1741206373.692 [DATMMP](INFO): Starting
2025-03-05T20:26:13.948Z,1741206373.948 [DATMMP](INFO): Starting
2025-03-05T20:26:13.950Z,1741206373.950 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-03-05T20:26:14.200Z,1741206374.200 [DATMMP](INFO): Starting
2025-03-05T20:26:14.452Z,1741206374.452 [DATMMP](INFO): Starting
2025-03-05T20:26:14.708Z,1741206374.708 [DATMMP](INFO): Starting
2025-03-05T20:26:14.960Z,1741206374.960 [DATMMP](INFO): Starting
2025-03-05T20:26:15.212Z,1741206375.212 [DATMMP](INFO): Starting
2025-03-05T20:26:15.464Z,1741206375.464 [DATMMP](INFO): Starting
2025-03-05T20:26:15.716Z,1741206375.716 [DATMMP](INFO): Starting
2025-03-05T20:26:15.968Z,1741206375.968 [DATMMP](INFO): Starting
2025-03-05T20:26:16.220Z,1741206376.220 [DATMMP](INFO): Starting
2025-03-05T20:26:16.472Z,1741206376.472 [DATMMP](INFO): Starting
2025-03-05T20:26:16.533Z,1741206376.533 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-03-05T20:26:16.728Z,1741206376.728 [DATMMP](INFO): Starting
2025-03-05T20:26:16.925Z,1741206376.925 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-03-05T20:26:16.980Z,1741206376.980 [DATMMP](INFO): Starting
2025-03-05T20:26:17.232Z,1741206377.232 [DATMMP](INFO): Starting
2025-03-05T20:26:17.484Z,1741206377.484 [DATMMP](INFO): Starting
2025-03-05T20:26:17.736Z,1741206377.736 [DATMMP](INFO): Starting
2025-03-05T20:26:17.989Z,1741206377.989 [DATMMP](INFO): Starting
2025-03-05T20:26:18.240Z,1741206378.240 [DATMMP](INFO): Starting
2025-03-05T20:26:18.492Z,1741206378.492 [DATMMP](INFO): Starting
2025-03-05T20:26:18.745Z,1741206378.745 [DATMMP](INFO): Starting
2025-03-05T20:26:18.996Z,1741206378.996 [DATMMP](INFO): Starting
2025-03-05T20:26:19.248Z,1741206379.248 [DATMMP](INFO): Starting
2025-03-05T20:26:19.500Z,1741206379.500 [DATMMP](INFO): Starting
2025-03-05T20:26:19.752Z,1741206379.752 [DATMMP](INFO): Starting
2025-03-05T20:26:20.004Z,1741206380.004 [DATMMP](INFO): Starting
2025-03-05T20:26:20.256Z,1741206380.256 [DATMMP](INFO): Starting
2025-03-05T20:26:20.508Z,1741206380.508 [DATMMP](INFO): Starting
2025-03-05T20:26:20.760Z,1741206380.760 [DATMMP](INFO): Starting
2025-03-05T20:26:21.012Z,1741206381.012 [DATMMP](INFO): Starting
2025-03-05T20:26:21.264Z,1741206381.264 [DATMMP](INFO): Starting
2025-03-05T20:26:21.516Z,1741206381.516 [DATMMP](INFO): Starting
2025-03-05T20:26:21.768Z,1741206381.768 [DATMMP](INFO): Starting
2025-03-05T20:26:22.020Z,1741206382.020 [DATMMP](INFO): Starting
2025-03-05T20:26:22.020Z,1741206382.020 [DATMMP](INFO): DAT read:
2025-03-05T20:26:22.021Z,1741206382.021 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-03-05T20:26:22.272Z,1741206382.272 [DATMMP](INFO): Starting
2025-03-05T20:26:22.524Z,1741206382.524 [DATMMP](INFO): Starting
2025-03-05T20:26:22.776Z,1741206382.776 [DATMMP](INFO): Starting
2025-03-05T20:26:23.028Z,1741206383.028 [DATMMP](INFO): Starting
2025-03-05T20:26:23.280Z,1741206383.280 [DATMMP](INFO): Starting
2025-03-05T20:26:23.532Z,1741206383.532 [DATMMP](INFO): Starting
2025-03-05T20:26:23.784Z,1741206383.784 [DATMMP](INFO): Starting
2025-03-05T20:26:23.785Z,1741206383.785 [DATMMP](INFO): DAT read: MF Frequency Band
2025-03-05T20:26:23.786Z,1741206383.786 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-03-05T20:26:23.786Z,1741206383.786 [DATMMP](INFO): DAT read: Feb 5 2000 20:26:18
2025-03-05T20:26:24.036Z,1741206384.036 [DATMMP](INFO): Starting
2025-03-05T20:26:24.288Z,1741206384.288 [DATMMP](INFO): Starting
2025-03-05T20:26:24.540Z,1741206384.540 [DATMMP](INFO): Starting
2025-03-05T20:26:24.792Z,1741206384.792 [DATMMP](INFO): Starting
2025-03-05T20:26:24.793Z,1741206384.793 [DATMMP](INFO): DAT read: Features enabled [Bearing]
2025-03-05T20:26:24.794Z,1741206384.794 [DATMMP](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2025-03-05T20:26:24.794Z,1741206384.794 [DATMMP](INFO): commRate: 1200
2025-03-05T20:26:25.044Z,1741206385.044 [DATMMP](INFO): Starting
2025-03-05T20:26:25.296Z,1741206385.296 [DATMMP](INFO): Starting
2025-03-05T20:26:25.548Z,1741206385.548 [DATMMP](INFO): Starting
2025-03-05T20:26:25.800Z,1741206385.800 [DATMMP](INFO): Starting
2025-03-05T20:26:26.052Z,1741206386.052 [DATMMP](INFO): Starting
2025-03-05T20:26:26.304Z,1741206386.304 [DATMMP](INFO): Starting
2025-03-05T20:26:26.556Z,1741206386.556 [DATMMP](INFO): Starting
2025-03-05T20:26:26.808Z,1741206386.808 [DATMMP](INFO): Starting
2025-03-05T20:26:26.861Z,1741206386.861 [DATMMP](INFO): entering command mode
2025-03-05T20:26:27.060Z,1741206387.060 [DATMMP](INFO): Starting
2025-03-05T20:26:27.060Z,1741206387.060 [DATMMP](INFO): DAT read:
2025-03-05T20:26:27.061Z,1741206387.061 [DATMMP](INFO): DAT read: user:1>
2025-03-05T20:26:27.061Z,1741206387.061 [DATMMP](DEBUG): read user prompt 1: user:1>
2025-03-05T20:26:27.061Z,1741206387.061 [DATMMP](INFO): entering MMP mode
2025-03-05T20:26:27.312Z,1741206387.312 [DATMMP](INFO): Starting
2025-03-05T20:26:27.313Z,1741206387.313 [DATMMP](INFO): GSXN notify for xid: 0
2025-03-05T20:26:27.315Z,1741206387.315 [DATMMP](INFO): status rx: x1
2025-03-05T20:26:27.315Z,1741206387.315 [DATMMP](INFO): MMP status: 1: started
2025-03-05T20:26:27.315Z,1741206387.315 [DATMMP](INFO): Received message type: status
2025-03-05T20:26:27.315Z,1741206387.315 [DATMMP](INFO): Handled
2025-03-05T20:26:27.564Z,1741206387.564 [DATMMP](INFO): Starting
2025-03-05T20:26:27.565Z,1741206387.565 [DATMMP](INFO): Sent Tx Power Config 8
2025-03-05T20:26:27.566Z,1741206387.566 [DATMMP](INFO): Setting local address: 5
2025-03-05T20:26:27.574Z,1741206387.574 [DATMMP](INFO): Setting time to: 20:26:27 And date to:3/5/2025
2025-03-05T20:26:27.816Z,1741206387.816 [DATMMP](INFO): Starting
2025-03-05T20:26:27.816Z,1741206387.816 [DATMMP](INFO): GSXN notify for xid: 0
2025-03-05T20:26:27.817Z,1741206387.817 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0
2025-03-05T20:26:27.817Z,1741206387.817 [DATMMP](INFO): Received message type: mdmpower
2025-03-05T20:26:27.818Z,1741206387.818 [DATMMP](INFO): Handled
2025-03-05T20:26:28.068Z,1741206388.068 [DATMMP](INFO): Starting
2025-03-05T20:26:28.069Z,1741206388.069 [DATMMP](INFO): GSXN notify for xid: 10
2025-03-05T20:26:28.070Z,1741206388.070 [DATMMP](INFO): sreg_txpower rx: x8
2025-03-05T20:26:28.070Z,1741206388.070 [DATMMP](INFO): Received message type: sreg_txpower
2025-03-05T20:26:28.070Z,1741206388.070 [DATMMP](INFO): Match for : sreg_txpower
2025-03-05T20:26:28.071Z,1741206388.071 [DATMMP](INFO): ACK
2025-03-05T20:26:28.320Z,1741206388.320 [DATMMP](INFO): Starting
2025-03-05T20:26:28.321Z,1741206388.321 [DATMMP](INFO): GSXN notify for xid: 0
2025-03-05T20:26:28.321Z,1741206388.321 [DATMMP](INFO): mdmlocal rx: x5 x0 x0 x0
2025-03-05T20:26:28.322Z,1741206388.322 [DATMMP](INFO): Received message type: mdmlocal
2025-03-05T20:26:28.322Z,1741206388.322 [DATMMP](INFO): Handled
2025-03-05T20:26:28.572Z,1741206388.572 [DATMMP](INFO): Starting
2025-03-05T20:26:28.573Z,1741206388.573 [DATMMP](INFO): GSXN notify for xid: 11
2025-03-05T20:26:28.574Z,1741206388.574 [DATMMP](INFO): sreg_locaddr rx: x5
2025-03-05T20:26:28.574Z,1741206388.574 [DATMMP](INFO): Received message type: sreg_locaddr
2025-03-05T20:26:28.574Z,1741206388.574 [DATMMP](INFO): Match for : sreg_locaddr
2025-03-05T20:26:28.575Z,1741206388.575 [DATMMP](INFO): ACK
2025-03-05T20:26:28.824Z,1741206388.824 [DATMMP](INFO): Starting
2025-03-05T20:26:28.824Z,1741206388.824 [DATMMP](INFO): GSXN notify for xid: 12
2025-03-05T20:26:28.826Z,1741206388.826 [DATMMP](INFO): timedate rx: x0 x14 x1A x1B x2 x5 x7D x0
2025-03-05T20:26:28.826Z,1741206388.826 [DATMMP](INFO): Received message type: timedate
2025-03-05T20:26:28.826Z,1741206388.826 [DATMMP](INFO): Match for : timedate
2025-03-05T20:26:28.826Z,1741206388.826 [DATMMP](INFO): ACK
2025-03-05T20:26:29.076Z,1741206389.076 [DATMMP](INFO): Starting
2025-03-05T20:26:29.076Z,1741206389.076 [DATMMP](INFO): GSXN notify for xid: 0
2025-03-05T20:26:29.077Z,1741206389.077 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0
2025-03-05T20:26:29.077Z,1741206389.077 [DATMMP](INFO): Received message type: sys_verb
2025-03-05T20:26:29.077Z,1741206389.077 [DATMMP](INFO): Handled
2025-03-05T20:26:29.328Z,1741206389.328 [DATMMP](INFO): Starting
2025-03-05T20:26:29.328Z,1741206389.328 [DATMMP](INFO): GSXN notify for xid: 13
2025-03-05T20:26:29.329Z,1741206389.329 [DATMMP](INFO): sreg_verbosity rx: x0
2025-03-05T20:26:29.329Z,1741206389.329 [DATMMP](INFO): Received message type: sreg_verbosity
2025-03-05T20:26:29.329Z,1741206389.329 [DATMMP](INFO): Match for : sreg_verbosity
2025-03-05T20:26:29.329Z,1741206389.329 [DATMMP](INFO): ACK
2025-03-05T20:26:29.580Z,1741206389.580 [DATMMP](INFO): Starting
2025-03-05T20:26:29.580Z,1741206389.580 [DATMMP](INFO): GSXN notify for xid: 14
2025-03-05T20:26:29.581Z,1741206389.581 [DATMMP](INFO): version rx: x2 x5
2025-03-05T20:26:29.581Z,1741206389.581 [DATMMP](INFO): DatMMPVersion: 2.5
2025-03-05T20:26:29.582Z,1741206389.582 [DATMMP](INFO): Received message type: version
2025-03-05T20:26:29.582Z,1741206389.582 [DATMMP](INFO): Match for : version
2025-03-05T20:26:29.582Z,1741206389.582 [DATMMP](INFO): ACK
2025-03-05T20:26:29.582Z,1741206389.582 [DATMMP](INFO): in MMP mode: config complete going to runnable
2025-03-05T20:26:39.347Z,1741206399.347 [NAL9602](INFO): Powering up NAL9602
2025-03-05T20:26:42.940Z,1741206402.940 [DATMMP](INFO): GSXN notify for xid: 0
2025-03-05T20:26:42.941Z,1741206402.941 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2025-03-05T20:26:42.942Z,1741206402.942 [DATMMP](INFO): Received message type: timesync
2025-03-05T20:26:42.942Z,1741206402.942 [DATMMP](INFO): Handled
2025-03-05T20:26:50.244Z,1741206410.244 [NAL9602](INFO): NAL9602 initialized
2025-03-05T20:26:52.768Z,1741206412.768 [DATMMP](INFO): GSXN notify for xid: 0
2025-03-05T20:26:52.769Z,1741206412.769 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2025-03-05T20:26:52.770Z,1741206412.770 [DATMMP](INFO): Received message type: timesync
2025-03-05T20:26:52.770Z,1741206412.770 [DATMMP](INFO): Handled
2025-03-05T20:27:18.554Z,1741206438.554 [SBIT](IMPORTANT): Beginning Startup BIT
2025-03-05T20:27:18.558Z,1741206438.558 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T20:27:29.525Z,1741206449.525 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006131
CHAN A1 (24V): 0.000360
CHAN A2 (12V): -0.005105
CHAN A3 (5V): -0.002980
CHAN B0 (3.3V): -0.000872
CHAN B1 (3.15aV): -0.000994
CHAN B2 (3.15bV): -0.000823
CHAN B3 (GND): 0.000365
OPEN: 0.006956
Full Scale: +/- 1 mA
2025-03-05T20:28:12.322Z,1741206492.322 [SBIT](IMPORTANT): SBIT PASSED
2025-03-05T20:28:12.323Z,1741206492.323 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-03-05T20:28:12.323Z,1741206492.323 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;
2025-03-05T20:28:12.323Z,1741206492.323 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2025-03-05T20:28:12.328Z,1741206492.328 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2025-03-05T20:28:12.328Z,1741206492.328 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2025-03-05T20:28:12.328Z,1741206492.328 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=214.355421 cubic_centimeter;
2025-03-05T20:28:12.328Z,1741206492.328 [SBIT](IMPORTANT): VerticalControl.massDefault=12.200269 millimeter;
2025-03-05T20:28:12.697Z,1741206492.697 [MissionManager](IMPORTANT): Started mission Startup
2025-03-05T20:28:12.698Z,1741206492.698 [Startup] Running Loop=1
2025-03-05T20:28:12.698Z,1741206492.698 [Startup](DEBUG): Aggregate::initialize Startup
2025-03-05T20:28:12.698Z,1741206492.698 [Startup:A.GoToSurface] Running Loop=1
2025-03-05T20:28:12.698Z,1741206492.698 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-05T20:28:12.698Z,1741206492.698 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-05T20:28:12.699Z,1741206492.699 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-05T20:28:12.699Z,1741206492.699 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-05T20:28:12.699Z,1741206492.699 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-05T20:28:12.700Z,1741206492.700 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-05T20:28:12.700Z,1741206492.700 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-05T20:28:12.702Z,1741206492.702 [Startup:StartupSatComms] Running Loop=1
2025-03-05T20:28:12.702Z,1741206492.702 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-03-05T20:28:12.702Z,1741206492.702 [Startup:StartupSatComms:A] Running Loop=1
2025-03-05T20:28:13.086Z,1741206493.086 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-03-05T20:28:20.985Z,1741206500.985 [CommandExec](IMPORTANT): got command strobe off
2025-03-05T20:28:20.985Z,1741206500.985 [CommandExec](IMPORTANT): Deactivating strobe
2025-03-05T20:28:21.906Z,1741206501.906 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004333
2025-03-05T20:28:51.488Z,1741206531.488 [CommandExec](IMPORTANT): got command failComponent
2025-03-05T20:28:51.489Z,1741206531.489 [CommandExec](IMPORTANT): Failed components:
2025-03-05T20:28:51.489Z,1741206531.489 [CommandExec](IMPORTANT): No failed Components.
2025-03-05T20:28:58.365Z,1741206538.365 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T20:28:58.474Z,1741206538.474 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T20:29:09.248Z,1741206549.248 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006028
CHAN A1 (24V): 0.000613
CHAN A2 (12V): -0.005556
CHAN A3 (5V): -0.002478
CHAN B0 (3.3V): -0.001076
CHAN B1 (3.15aV): -0.000857
CHAN B2 (3.15bV): -0.001291
CHAN B3 (GND): 0.000580
OPEN: 0.006810
Full Scale: +/- 1 mA
2025-03-05T20:29:10.034Z,1741206550.034 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-03-05T20:29:10.034Z,1741206550.034 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-05T20:29:10.044Z,1741206550.044 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-05T20:29:10.463Z,1741206550.463 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-05T20:29:10.463Z,1741206550.463 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-03-05T20:29:12.869Z,1741206552.869 [Startup:StartupSatComms:A](INFO): Timed out from 2025-03-05T20:28:12.7Z
2025-03-05T20:29:12.869Z,1741206552.869 [Startup:StartupSatComms:A] Stopped
2025-03-05T20:29:12.870Z,1741206552.870 [Startup:StartupSatComms:B] Running Loop=1
2025-03-05T20:29:13.274Z,1741206553.274 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-05T20:29:19.796Z,1741206559.796 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20250305T201654/Courier0004.lzma
2025-03-05T20:29:20.798Z,1741206560.798 [DataOverHttps](INFO): Moved sent file to Logs/20250305T201654/Courier0004.lzma.bak
2025-03-05T20:29:20.798Z,1741206560.798 [DataOverHttps](INFO): SBD MOMSN=24089044
2025-03-05T20:29:37.255Z,1741206577.255 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250305T202558/Courier0000.lzma
2025-03-05T20:29:38.259Z,1741206578.259 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0000.lzma.bak
2025-03-05T20:29:38.259Z,1741206578.259 [DataOverHttps](INFO): SBD MOMSN=24089047
2025-03-05T20:29:51.637Z,1741206591.637 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-03-05T20:29:55.282Z,1741206595.282 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20250305T201654/Express0005.lzma
2025-03-05T20:29:56.282Z,1741206596.282 [DataOverHttps](INFO): Moved sent file to Logs/20250305T201654/Express0005.lzma.bak
2025-03-05T20:29:56.282Z,1741206596.282 [DataOverHttps](INFO): SBD MOMSN=24089050
2025-03-05T20:30:13.072Z,1741206613.072 [Startup:StartupSatComms:B](INFO): Timed out from 2025-03-05T20:29:12.9Z
2025-03-05T20:30:13.072Z,1741206613.072 [Startup:StartupSatComms:B] Stopped
2025-03-05T20:30:13.072Z,1741206613.072 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-03-05T20:30:13.073Z,1741206613.073 [Startup:StartupSatComms] Stopped
2025-03-05T20:30:13.073Z,1741206613.073 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-03-05T20:30:13.074Z,1741206613.074 [Startup](INFO): Completed Startup
2025-03-05T20:30:13.074Z,1741206613.074 [MissionManager](INFO): Startup is completed.
2025-03-05T20:30:13.074Z,1741206613.074 [MissionManager](INFO): Uninitializing Mission Startup
2025-03-05T20:30:13.074Z,1741206613.074 [Startup] Stopped
2025-03-05T20:30:13.074Z,1741206613.074 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-03-05T20:30:13.074Z,1741206613.074 [Startup:A.GoToSurface] Stopped
2025-03-05T20:30:13.074Z,1741206613.074 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-05T20:30:13.301Z,1741206613.301 [DataOverHttps](INFO): Sending 962 bytes from file Logs/20250305T202558/Express0001.lzma
2025-03-05T20:30:13.475Z,1741206613.475 [MissionManager](IMPORTANT): Started mission Default
2025-03-05T20:30:13.475Z,1741206613.475 [Default] Running Loop=1
2025-03-05T20:30:13.475Z,1741206613.475 [Default](DEBUG): Aggregate::initialize Default
2025-03-05T20:30:13.475Z,1741206613.475 [Default:B.GoToSurface] Running Loop=1
2025-03-05T20:30:13.475Z,1741206613.475 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-05T20:30:13.488Z,1741206613.488 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-05T20:30:13.488Z,1741206613.488 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-05T20:30:13.488Z,1741206613.488 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-05T20:30:13.489Z,1741206613.489 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-05T20:30:13.489Z,1741206613.489 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-05T20:30:13.489Z,1741206613.489 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-05T20:30:13.490Z,1741206613.490 [Default:A.Wait] Running Loop=1
2025-03-05T20:30:13.490Z,1741206613.490 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-05T20:30:14.301Z,1741206614.301 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0001.lzma.bak
2025-03-05T20:30:14.302Z,1741206614.302 [DataOverHttps](INFO): SBD MOMSN=24089058
2025-03-05T20:30:18.719Z,1741206618.719 [NAL9602](INFO): SBD MO Status=2, MOMSN=18812, MT Status=2, MTMSN=0
2025-03-05T20:30:18.719Z,1741206618.719 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T20:30:26.806Z,1741206626.806 [Default:A.Wait](INFO): Done Waiting.
2025-03-05T20:30:26.806Z,1741206626.806 [Default:A.Wait] Stopped
2025-03-05T20:30:26.806Z,1741206626.806 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T20:30:27.227Z,1741206627.227 [Default:CheckIn] Running Loop=1
2025-03-05T20:30:27.227Z,1741206627.227 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T20:30:27.227Z,1741206627.227 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T20:30:27.605Z,1741206627.605 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-05T20:30:36.080Z,1741206636.080 [NAL9602](INFO): SBD MO Status=2, MOMSN=18812, MT Status=2, MTMSN=0
2025-03-05T20:30:36.081Z,1741206636.081 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T20:31:53.240Z,1741206713.240 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T20:32:11.060Z,1741206731.060 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-03-05T20:32:11.060Z,1741206731.060 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-05T20:32:11.071Z,1741206731.071 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-05T20:32:11.470Z,1741206731.470 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-05T20:32:11.470Z,1741206731.470 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-03-05T20:34:45.355Z,1741206885.355 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-03-05T20:34:45.361Z,1741206885.361 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2025-03-05T20:34:45.401Z,1741206885.401 [BPC1](INFO): Received data from all battery sticks.
2025-03-05T20:35:12.022Z,1741206912.022 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-03-05T20:35:12.022Z,1741206912.022 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-05T20:35:12.061Z,1741206912.061 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-05T20:35:12.434Z,1741206912.434 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-05T20:35:12.434Z,1741206912.434 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-03-05T20:35:27.377Z,1741206927.377 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-05T20:30:27.2Z
2025-03-05T20:35:27.377Z,1741206927.377 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T20:35:27.377Z,1741206927.377 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T20:35:27.794Z,1741206927.794 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-05T20:35:34.280Z,1741206934.280 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250305T202558/Courier0004.lzma
2025-03-05T20:35:35.281Z,1741206935.281 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0004.lzma.bak
2025-03-05T20:35:35.282Z,1741206935.282 [DataOverHttps](INFO): SBD MOMSN=24089106
2025-03-05T20:35:59.706Z,1741206959.706 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250305T202558/Express0005.lzma
2025-03-05T20:35:59.987Z,1741206959.987 [CommandLine](INFO): End of History
2025-03-05T20:36:00.707Z,1741206960.707 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0005.lzma.bak
2025-03-05T20:36:00.707Z,1741206960.707 [DataOverHttps](INFO): SBD MOMSN=24089109
2025-03-05T20:36:03.346Z,1741206963.346 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T20:36:03.346Z,1741206963.346 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T20:36:03.346Z,1741206963.346 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T20:36:22.037Z,1741206982.037 [CommandExec](IMPORTANT): got command get
2025-03-05T20:36:22.038Z,1741206982.038 [CommandExec](FAULT): Incomplete syntax. Try: help get
2025-03-05T20:36:30.654Z,1741206990.654 [CommandExec](IMPORTANT): got command get platform_mass_position
2025-03-05T20:36:30.655Z,1741206990.655 [CommandExec](IMPORTANT): platform_mass_position 0.012193 m
2025-03-05T20:36:51.807Z,1741207011.807 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-05T20:36:51.807Z,1741207011.807 [NAL9602] Data Fault, FailCount= 1
2025-03-05T20:36:51.807Z,1741207011.807 [NAL9602](ERROR): Data Fault
2025-03-05T20:36:51.824Z,1741207011.824 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-05T20:36:52.229Z,1741207012.229 [NAL9602](INFO): Powering down
2025-03-05T20:36:53.024Z,1741207013.024 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-05T20:36:53.025Z,1741207013.025 [NAL9602] No Fault, FailCount= 1
2025-03-05T20:37:13.726Z,1741207033.726 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200 cubic_centimeter
2025-03-05T20:37:13.730Z,1741207033.730 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2025-03-05T20:37:14.052Z,1741207034.052 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-05T20:37:22.503Z,1741207042.503 [NAL9602](INFO): Powering up NAL9602
2025-03-05T20:37:33.418Z,1741207053.418 [NAL9602](INFO): NAL9602 initialized
2025-03-05T20:38:13.032Z,1741207093.032 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-03-05T20:38:13.032Z,1741207093.032 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-05T20:38:13.074Z,1741207093.074 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-05T20:38:13.489Z,1741207093.489 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-05T20:38:13.489Z,1741207093.489 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-03-05T20:38:26.840Z,1741207106.840 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 25 millimeter
2025-03-05T20:38:26.843Z,1741207106.843 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2025-03-05T20:38:27.205Z,1741207107.205 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-05T20:39:28.187Z,1741207168.187 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300 cubic_centimeter
2025-03-05T20:40:24.308Z,1741207224.308 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00000000000000,35.0,+18.2,000050,+00000,A
2025-03-05T20:40:24.308Z,1741207224.308 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+18.2,000050,+00000,A
2025-03-05T20:40:27.821Z,1741207227.821 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 500 cubic_centimeter
2025-03-05T20:40:46.125Z,1741207246.125 [DVL_micro](ERROR): Failed to parse::BD,+00000000.00,+00000000.00,+00000000.00,0000.20,000.00
2025-03-05T20:41:03.945Z,1741207263.945 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T20:41:03.946Z,1741207263.946 [Default:CheckIn:C.Wait] Stopped
2025-03-05T20:41:03.946Z,1741207263.946 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T20:41:03.946Z,1741207263.946 [Default:CheckIn:D] Running Loop=1
2025-03-05T20:41:04.334Z,1741207264.334 [Default:CheckIn:D] Stopped
2025-03-05T20:41:04.334Z,1741207264.334 [Default:CheckIn:E] Running Loop=1
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.847645 min
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn:E] Stopped
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn] Stopped
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn](INFO): Running loop #2
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn] Running Loop=2
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T20:41:04.742Z,1741207264.742 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T20:41:14.004Z,1741207274.004 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-03-05T20:41:14.004Z,1741207274.004 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-05T20:41:14.016Z,1741207274.016 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-05T20:41:14.433Z,1741207274.433 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-05T20:41:14.433Z,1741207274.433 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-03-05T20:41:23.426Z,1741207283.426 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 700 cubic_centimeter
2025-03-05T20:42:33.049Z,1741207353.049 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 600 cubic_centimeter
2025-03-05T20:43:40.257Z,1741207420.257 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204336.00,A,3648.16675,N,12147.28045,W,0.058,157.50,050325,,,A*76
2025-03-05T20:43:40.277Z,1741207420.277 [NAL9602](INFO): GPS fix at 20250305T204336: (36.802779, -121.788008)
2025-03-05T20:43:40.291Z,1741207420.291 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T20:43:40.291Z,1741207420.291 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T20:43:48.068Z,1741207428.068 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20250305T202558/Courier0007.lzma
2025-03-05T20:43:49.070Z,1741207429.070 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0007.lzma.bak
2025-03-05T20:43:49.070Z,1741207429.070 [DataOverHttps](INFO): SBD MOMSN=24090972
2025-03-05T20:44:09.404Z,1741207449.404 [DataOverHttps](INFO): Sending 527 bytes from file Logs/20250305T202558/Express0008.lzma
2025-03-05T20:44:10.410Z,1741207450.410 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0008.lzma.bak
2025-03-05T20:44:10.410Z,1741207450.410 [DataOverHttps](INFO): SBD MOMSN=24090975
2025-03-05T20:44:12.584Z,1741207452.584 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T20:44:13.015Z,1741207453.015 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T20:44:13.015Z,1741207453.015 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T20:44:13.015Z,1741207453.015 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T20:49:13.644Z,1741207753.644 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T20:49:13.644Z,1741207753.644 [Default:CheckIn:C.Wait] Stopped
2025-03-05T20:49:13.645Z,1741207753.645 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T20:49:13.645Z,1741207753.645 [Default:CheckIn:D] Running Loop=1
2025-03-05T20:49:14.047Z,1741207754.047 [Default:CheckIn:D] Stopped
2025-03-05T20:49:14.047Z,1741207754.047 [Default:CheckIn:E] Running Loop=1
2025-03-05T20:49:14.438Z,1741207754.438 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.009530 min
2025-03-05T20:49:14.438Z,1741207754.438 [Default:CheckIn:E] Stopped
2025-03-05T20:49:14.439Z,1741207754.439 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T20:49:14.439Z,1741207754.439 [Default:CheckIn] Stopped
2025-03-05T20:49:14.439Z,1741207754.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T20:49:14.439Z,1741207754.439 [Default:CheckIn](INFO): Running loop #3
2025-03-05T20:49:14.439Z,1741207754.439 [Default:CheckIn] Running Loop=3
2025-03-05T20:49:14.439Z,1741207754.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T20:49:14.439Z,1741207754.439 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T20:49:16.453Z,1741207756.453 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204912.00,A,3648.16585,N,12147.28170,W,0.078,258.87,050325,,,D*70
2025-03-05T20:49:16.455Z,1741207756.455 [NAL9602](INFO): GPS fix at 20250305T204912: (36.802764, -121.788028)
2025-03-05T20:49:16.465Z,1741207756.465 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T20:49:16.466Z,1741207756.466 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T20:49:23.758Z,1741207763.758 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250305T202558/Courier0010.lzma
2025-03-05T20:49:24.750Z,1741207764.750 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0010.lzma.bak
2025-03-05T20:49:24.750Z,1741207764.750 [DataOverHttps](INFO): SBD MOMSN=24092381
2025-03-05T20:49:42.447Z,1741207782.447 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20250305T202558/Express0011.lzma
2025-03-05T20:49:43.450Z,1741207783.450 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0011.lzma.bak
2025-03-05T20:49:43.450Z,1741207783.450 [DataOverHttps](INFO): SBD MOMSN=24092386
2025-03-05T20:49:45.956Z,1741207785.956 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T20:49:45.956Z,1741207785.956 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T20:49:45.956Z,1741207785.956 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T20:54:18.702Z,1741208058.702 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T20:54:46.594Z,1741208086.594 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T20:54:46.594Z,1741208086.594 [Default:CheckIn:C.Wait] Stopped
2025-03-05T20:54:46.594Z,1741208086.594 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T20:54:46.595Z,1741208086.595 [Default:CheckIn:D] Running Loop=1
2025-03-05T20:54:46.991Z,1741208086.991 [Default:CheckIn:D] Stopped
2025-03-05T20:54:46.991Z,1741208086.991 [Default:CheckIn:E] Running Loop=1
2025-03-05T20:54:47.399Z,1741208087.399 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.558594 min
2025-03-05T20:54:47.399Z,1741208087.399 [Default:CheckIn:E] Stopped
2025-03-05T20:54:47.399Z,1741208087.399 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T20:54:47.399Z,1741208087.399 [Default:CheckIn] Stopped
2025-03-05T20:54:47.399Z,1741208087.399 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T20:54:47.400Z,1741208087.400 [Default:CheckIn](INFO): Running loop #4
2025-03-05T20:54:47.400Z,1741208087.400 [Default:CheckIn] Running Loop=4
2025-03-05T20:54:47.400Z,1741208087.400 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T20:54:47.400Z,1741208087.400 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T20:54:49.410Z,1741208089.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205445.00,A,3648.16535,N,12147.28335,W,0.117,142.77,050325,,,D*79
2025-03-05T20:54:49.414Z,1741208089.414 [NAL9602](INFO): GPS fix at 20250305T205445: (36.802756, -121.788056)
2025-03-05T20:54:49.466Z,1741208089.466 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T20:54:49.466Z,1741208089.466 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T20:54:57.043Z,1741208097.043 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0013.lzma
2025-03-05T20:54:58.046Z,1741208098.046 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0013.lzma.bak
2025-03-05T20:54:58.046Z,1741208098.046 [DataOverHttps](INFO): SBD MOMSN=24093780
2025-03-05T20:55:17.263Z,1741208117.263 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20250305T202558/Express0014.lzma
2025-03-05T20:55:18.266Z,1741208118.266 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0014.lzma.bak
2025-03-05T20:55:18.266Z,1741208118.266 [DataOverHttps](INFO): SBD MOMSN=24093783
2025-03-05T20:55:20.964Z,1741208120.964 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T20:55:20.964Z,1741208120.964 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T20:55:20.964Z,1741208120.964 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T20:55:21.750Z,1741208121.750 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:00:21.529Z,1741208421.529 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:00:21.529Z,1741208421.529 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:00:21.529Z,1741208421.529 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:00:21.529Z,1741208421.529 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:00:21.935Z,1741208421.935 [Default:CheckIn:D] Stopped
2025-03-05T21:00:21.935Z,1741208421.935 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:00:22.342Z,1741208422.342 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.140995 min
2025-03-05T21:00:22.342Z,1741208422.342 [Default:CheckIn:E] Stopped
2025-03-05T21:00:22.342Z,1741208422.342 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:00:22.342Z,1741208422.342 [Default:CheckIn] Stopped
2025-03-05T21:00:22.343Z,1741208422.343 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:00:22.343Z,1741208422.343 [Default:CheckIn](INFO): Running loop #5
2025-03-05T21:00:22.343Z,1741208422.343 [Default:CheckIn] Running Loop=5
2025-03-05T21:00:22.343Z,1741208422.343 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:00:22.343Z,1741208422.343 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:00:24.351Z,1741208424.351 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210020.00,A,3648.16706,N,12147.28076,W,0.058,173.61,050325,,,D*73
2025-03-05T21:00:24.354Z,1741208424.354 [NAL9602](INFO): GPS fix at 20250305T210020: (36.802784, -121.788013)
2025-03-05T21:00:24.388Z,1741208424.388 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:00:24.388Z,1741208424.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:00:33.663Z,1741208433.663 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250305T202558/Courier0016.lzma
2025-03-05T21:00:34.666Z,1741208434.666 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0016.lzma.bak
2025-03-05T21:00:34.666Z,1741208434.666 [DataOverHttps](INFO): SBD MOMSN=24093793
2025-03-05T21:00:53.039Z,1741208453.039 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250305T202558/Express0017.lzma
2025-03-05T21:00:54.042Z,1741208454.042 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0017.lzma.bak
2025-03-05T21:00:54.042Z,1741208454.042 [DataOverHttps](INFO): SBD MOMSN=24093796
2025-03-05T21:00:55.123Z,1741208455.123 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-05T21:00:55.204Z,1741208455.204 [NAL9602](ERROR): received:
+CSQ:0
OK812, 2, 0, 0, 0
OK
2025-03-05T21:00:56.748Z,1741208456.748 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:00:56.749Z,1741208456.749 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:00:56.749Z,1741208456.749 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:05:26.579Z,1741208726.579 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T21:05:57.285Z,1741208757.285 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:05:57.296Z,1741208757.296 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:05:57.296Z,1741208757.296 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:05:57.296Z,1741208757.296 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:05:57.297Z,1741208757.297 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:05:57.711Z,1741208757.711 [Default:CheckIn:D] Stopped
2025-03-05T21:05:57.711Z,1741208757.711 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:05:58.094Z,1741208758.094 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.737264 min
2025-03-05T21:05:58.094Z,1741208758.094 [Default:CheckIn:E] Stopped
2025-03-05T21:05:58.094Z,1741208758.094 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:05:58.094Z,1741208758.094 [Default:CheckIn] Stopped
2025-03-05T21:05:58.094Z,1741208758.094 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:05:58.094Z,1741208758.094 [Default:CheckIn](INFO): Running loop #6
2025-03-05T21:05:58.095Z,1741208758.095 [Default:CheckIn] Running Loop=6
2025-03-05T21:05:58.095Z,1741208758.095 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:05:58.095Z,1741208758.095 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:06:00.105Z,1741208760.105 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210556.00,A,3648.16354,N,12147.28263,W,0.389,173.61,050325,,,A*78
2025-03-05T21:06:00.108Z,1741208760.108 [NAL9602](INFO): GPS fix at 20250305T210556: (36.802726, -121.788044)
2025-03-05T21:06:00.118Z,1741208760.118 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:06:00.118Z,1741208760.118 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:06:07.843Z,1741208767.843 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250305T202558/Courier0019.lzma
2025-03-05T21:06:08.846Z,1741208768.846 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0019.lzma.bak
2025-03-05T21:06:08.846Z,1741208768.846 [DataOverHttps](INFO): SBD MOMSN=24094731
2025-03-05T21:06:26.332Z,1741208786.332 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20250305T202558/Express0020.lzma
2025-03-05T21:06:27.334Z,1741208787.334 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0020.lzma.bak
2025-03-05T21:06:27.334Z,1741208787.334 [DataOverHttps](INFO): SBD MOMSN=24094734
2025-03-05T21:06:30.491Z,1741208790.491 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:06:30.491Z,1741208790.491 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:06:30.491Z,1741208790.491 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:06:30.865Z,1741208790.865 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-05T21:06:30.948Z,1741208790.948 [NAL9602](ERROR): received:
+CSQ:0
OK812, 2, 0, 0, 0
OK
2025-03-05T21:08:57.473Z,1741208937.473 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00000000000000,35.0,+18.3,0
2025-03-05T21:08:57.474Z,1741208937.474 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+18.3,0
2025-03-05T21:11:02.713Z,1741209062.713 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T21:11:31.409Z,1741209091.409 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:11:31.409Z,1741209091.409 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:11:31.409Z,1741209091.409 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:11:31.409Z,1741209091.409 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:11:31.810Z,1741209091.810 [Default:CheckIn:D] Stopped
2025-03-05T21:11:31.810Z,1741209091.810 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.305579 min
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn:E] Stopped
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn] Stopped
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn](INFO): Running loop #7
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn] Running Loop=7
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:11:32.238Z,1741209092.238 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:11:34.226Z,1741209094.226 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211130.00,A,3648.17020,N,12147.28335,W,0.350,308.91,050325,,,A*7B
2025-03-05T21:11:34.228Z,1741209094.228 [NAL9602](INFO): GPS fix at 20250305T211130: (36.802837, -121.788056)
2025-03-05T21:11:34.259Z,1741209094.259 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:11:34.259Z,1741209094.259 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:11:42.307Z,1741209102.307 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0022.lzma
2025-03-05T21:11:43.310Z,1741209103.310 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0022.lzma.bak
2025-03-05T21:11:43.310Z,1741209103.310 [DataOverHttps](INFO): SBD MOMSN=24095671
2025-03-05T21:12:00.524Z,1741209120.524 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20250305T202558/Express0023.lzma
2025-03-05T21:12:01.526Z,1741209121.526 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0023.lzma.bak
2025-03-05T21:12:01.526Z,1741209121.526 [DataOverHttps](INFO): SBD MOMSN=24096136
2025-03-05T21:12:04.152Z,1741209124.152 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:12:04.152Z,1741209124.152 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:12:04.153Z,1741209124.153 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:12:06.549Z,1741209126.549 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:14:09.065Z,1741209249.065 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:14:09.423Z,1741209249.423 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:14:20.317Z,1741209260.317 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011309
CHAN A1 (24V): 0.031358
CHAN A2 (12V): 0.003600
CHAN A3 (5V): -0.005480
CHAN B0 (3.3V): -0.005362
CHAN B1 (3.15aV): -0.005449
CHAN B2 (3.15bV): -0.004445
CHAN B3 (GND): -0.007419
OPEN: 0.006986
Full Scale: +/- 1 mA
2025-03-05T21:14:37.481Z,1741209277.481 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:14:37.671Z,1741209277.671 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:14:48.626Z,1741209288.626 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.010986
CHAN A1 (24V): 0.030681
CHAN A2 (12V): 0.002375
CHAN A3 (5V): -0.007116
CHAN B0 (3.3V): -0.006067
CHAN B1 (3.15aV): -0.006281
CHAN B2 (3.15bV): -0.005445
CHAN B3 (GND): -0.007749
OPEN: 0.006479
Full Scale: +/- 1 mA
2025-03-05T21:15:07.681Z,1741209307.681 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA4
2025-03-05T21:15:12.473Z,1741209312.473 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:15:12.826Z,1741209312.826 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:15:23.745Z,1741209323.745 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.010990
CHAN A1 (24V): 0.030384
CHAN A2 (12V): 0.002213
CHAN A3 (5V): -0.006386
CHAN B0 (3.3V): -0.006042
CHAN B1 (3.15aV): -0.005748
CHAN B2 (3.15bV): -0.004954
CHAN B3 (GND): -0.008125
OPEN: 0.006816
Full Scale: +/- 1 mA
2025-03-05T21:16:35.626Z,1741209395.626 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB3
2025-03-05T21:16:38.845Z,1741209398.845 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2025-03-05T21:16:47.325Z,1741209407.325 [DVL_micro](ERROR): No DVL communication! Re-initializing
2025-03-05T21:16:47.325Z,1741209407.325 [DVL_micro] Communications Fault, FailCount= 1
2025-03-05T21:16:47.325Z,1741209407.325 [DVL_micro](ERROR): Communications Fault
2025-03-05T21:16:47.375Z,1741209407.375 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-03-05T21:16:47.824Z,1741209407.824 [DVL_micro](INFO): Powering down
2025-03-05T21:16:48.561Z,1741209408.561 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-03-05T21:16:48.561Z,1741209408.561 [DVL_micro] No Fault, FailCount= 1
2025-03-05T21:17:04.715Z,1741209424.715 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:17:04.715Z,1741209424.715 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:17:04.715Z,1741209424.715 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:17:04.715Z,1741209424.715 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:17:05.120Z,1741209425.120 [Default:CheckIn:D] Stopped
2025-03-05T21:17:05.120Z,1741209425.120 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:17:05.515Z,1741209425.515 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.860738 min
2025-03-05T21:17:05.515Z,1741209425.515 [Default:CheckIn:E] Stopped
2025-03-05T21:17:05.515Z,1741209425.515 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:17:05.516Z,1741209425.516 [Default:CheckIn] Stopped
2025-03-05T21:17:05.516Z,1741209425.516 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:17:05.516Z,1741209425.516 [Default:CheckIn](INFO): Running loop #8
2025-03-05T21:17:05.516Z,1741209425.516 [Default:CheckIn] Running Loop=8
2025-03-05T21:17:05.516Z,1741209425.516 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:17:05.516Z,1741209425.516 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:17:07.534Z,1741209427.534 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211703.00,A,3648.17251,N,12147.27293,W,0.797,308.91,050325,,,A*74
2025-03-05T21:17:07.536Z,1741209427.536 [NAL9602](INFO): GPS fix at 20250305T211703: (36.802875, -121.787882)
2025-03-05T21:17:07.546Z,1741209427.546 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:17:07.546Z,1741209427.546 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:17:15.479Z,1741209435.479 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0025.lzma
2025-03-05T21:17:16.482Z,1741209436.482 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0025.lzma.bak
2025-03-05T21:17:16.482Z,1741209436.482 [DataOverHttps](INFO): SBD MOMSN=24097101
2025-03-05T21:17:26.292Z,1741209446.292 [CommandExec](IMPORTANT): got command get CBIT.gf24Offset
2025-03-05T21:17:26.293Z,1741209446.293 [CommandExec](IMPORTANT): CBIT.gf24Offset 148.000000 uA
2025-03-05T21:17:34.196Z,1741209454.196 [DataOverHttps](INFO): Sending 463 bytes from file Logs/20250305T202558/Express0026.lzma
2025-03-05T21:17:35.198Z,1741209455.198 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0026.lzma.bak
2025-03-05T21:17:35.198Z,1741209455.198 [DataOverHttps](INFO): SBD MOMSN=24097105
2025-03-05T21:17:35.681Z,1741209455.681 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:17:35.857Z,1741209455.857 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:17:37.853Z,1741209457.853 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:17:37.853Z,1741209457.853 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:17:37.853Z,1741209457.853 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:17:38.230Z,1741209458.230 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-05T21:17:38.308Z,1741209458.308 [NAL9602](ERROR): received:
+CSQ:0
OK812, 2, 0, 0, 0
OK
2025-03-05T21:17:46.752Z,1741209466.752 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011142
CHAN A1 (24V): 0.030728
CHAN A2 (12V): 0.002546
CHAN A3 (5V): -0.005873
CHAN B0 (3.3V): -0.005886
CHAN B1 (3.15aV): -0.004855
CHAN B2 (3.15bV): -0.004615
CHAN B3 (GND): -0.007599
OPEN: 0.005264
Full Scale: +/- 1 mA
2025-03-05T21:18:52.163Z,1741209532.163 [NAL9602](INFO): SBD MO Status=2, MOMSN=18812, MT Status=2, MTMSN=0
2025-03-05T21:18:52.163Z,1741209532.163 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:19:03.933Z,1741209543.933 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:19:04.305Z,1741209544.305 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:19:15.619Z,1741209555.619 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.003564
CHAN A1 (24V): 0.017584
CHAN A2 (12V): 0.000821
CHAN A3 (5V): -0.002469
CHAN B0 (3.3V): -0.002231
CHAN B1 (3.15aV): -0.002656
CHAN B2 (3.15bV): -0.002679
CHAN B3 (GND): -0.003643
OPEN: 0.005224
Full Scale: +/- 1 mA
2025-03-05T21:19:16.423Z,1741209556.423 [NAL9602](INFO): SBD MO Status=2, MOMSN=18812, MT Status=2, MTMSN=0
2025-03-05T21:19:16.423Z,1741209556.423 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:20:02.157Z,1741209602.157 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:20:02.483Z,1741209602.483 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:20:12.570Z,1741209612.570 [NAL9602](INFO): SBD MO Status=0, MOMSN=18812, MT Status=0, MTMSN=0
2025-03-05T21:20:12.570Z,1741209612.570 [NAL9602](INFO): No messages in MT queue
2025-03-05T21:20:13.391Z,1741209613.391 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.003643
CHAN A1 (24V): 0.017493
CHAN A2 (12V): 0.000595
CHAN A3 (5V): -0.002452
CHAN B0 (3.3V): -0.002305
CHAN B1 (3.15aV): -0.002568
CHAN B2 (3.15bV): -0.002483
CHAN B3 (GND): -0.003914
OPEN: 0.005012
Full Scale: +/- 1 mA
2025-03-05T21:20:26.265Z,1741209626.265 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:20:26.321Z,1741209626.321 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:20:37.227Z,1741209637.227 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.001876
CHAN A1 (24V): 0.017186
CHAN A2 (12V): 0.000410
CHAN A3 (5V): -0.003349
CHAN B0 (3.3V): -0.002897
CHAN B1 (3.15aV): -0.003127
CHAN B2 (3.15bV): -0.002915
CHAN B3 (GND): -0.003890
OPEN: 0.004827
Full Scale: +/- 1 mA
2025-03-05T21:20:43.286Z,1741209643.286 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:20:47.949Z,1741209647.949 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadA4
2025-03-05T21:20:51.301Z,1741209651.301 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:20:51.377Z,1741209651.377 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:20:58.377Z,1741209658.377 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadB3
2025-03-05T21:21:01.813Z,1741209661.813 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadB4
2025-03-05T21:21:02.301Z,1741209662.301 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.861056
CHAN A1 (24V): 0.795830
CHAN A2 (12V): 0.876610
CHAN A3 (5V): 0.178082
CHAN B0 (3.3V): 0.072961
CHAN B1 (3.15aV): 0.083079
CHAN B2 (3.15bV): 0.090645
CHAN B3 (GND): -0.003063
OPEN: 0.006007
Full Scale: +/- 1 mA
2025-03-05T21:21:14.697Z,1741209674.697 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:21:14.825Z,1741209674.825 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:21:25.722Z,1741209685.722 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.867229
CHAN A1 (24V): 0.800200
CHAN A2 (12V): 0.880273
CHAN A3 (5V): 0.230130
CHAN B0 (3.3V): 0.103864
CHAN B1 (3.15aV): 0.127134
CHAN B2 (3.15bV): 0.136954
CHAN B3 (GND): -0.003728
OPEN: 0.011174
Full Scale: +/- 1 mA
2025-03-05T21:21:56.766Z,1741209716.766 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA4
2025-03-05T21:21:59.273Z,1741209719.273 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:21:59.678Z,1741209719.678 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:22:10.554Z,1741209730.554 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.002755
CHAN A1 (24V): 0.017094
CHAN A2 (12V): 0.001027
CHAN A3 (5V): -0.002695
CHAN B0 (3.3V): -0.002281
CHAN B1 (3.15aV): -0.002629
CHAN B2 (3.15bV): -0.002308
CHAN B3 (GND): -0.003444
OPEN: 0.006942
Full Scale: +/- 1 mA
2025-03-05T21:22:19.701Z,1741209739.701 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadB4
2025-03-05T21:22:22.717Z,1741209742.717 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:22:23.070Z,1741209743.070 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:22:33.995Z,1741209753.995 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.002402
CHAN A1 (24V): 0.016300
CHAN A2 (12V): -0.000146
CHAN A3 (5V): -0.003290
CHAN B0 (3.3V): -0.002883
CHAN B1 (3.15aV): -0.002570
CHAN B2 (3.15bV): -0.002720
CHAN B3 (GND): -0.004611
OPEN: 0.006389
Full Scale: +/- 1 mA
2025-03-05T21:22:37.145Z,1741209757.145 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadA4
2025-03-05T21:22:38.421Z,1741209758.421 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:22:38.421Z,1741209758.421 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:22:38.422Z,1741209758.422 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:22:38.422Z,1741209758.422 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:22:38.819Z,1741209758.819 [Default:CheckIn:D] Stopped
2025-03-05T21:22:38.819Z,1741209758.819 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:22:39.231Z,1741209759.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.422396 min
2025-03-05T21:22:39.231Z,1741209759.231 [Default:CheckIn:E] Stopped
2025-03-05T21:22:39.231Z,1741209759.231 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:22:39.231Z,1741209759.231 [Default:CheckIn] Stopped
2025-03-05T21:22:39.231Z,1741209759.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:22:39.232Z,1741209759.232 [Default:CheckIn](INFO): Running loop #9
2025-03-05T21:22:39.232Z,1741209759.232 [Default:CheckIn] Running Loop=9
2025-03-05T21:22:39.232Z,1741209759.232 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:22:39.232Z,1741209759.232 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:22:39.361Z,1741209759.361 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:22:39.638Z,1741209759.638 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:22:41.235Z,1741209761.235 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212237.00,A,3648.16840,N,12147.28300,W,0.311,308.91,050325,,,A*70
2025-03-05T21:22:41.238Z,1741209761.238 [NAL9602](INFO): GPS fix at 20250305T212237: (36.802807, -121.788050)
2025-03-05T21:22:41.249Z,1741209761.249 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:22:41.249Z,1741209761.249 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:22:49.207Z,1741209769.207 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0028.lzma
2025-03-05T21:22:50.210Z,1741209770.210 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0028.lzma.bak
2025-03-05T21:22:50.210Z,1741209770.210 [DataOverHttps](INFO): SBD MOMSN=24098517
2025-03-05T21:22:50.584Z,1741209770.584 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.864737
CHAN A1 (24V): 0.799064
CHAN A2 (12V): 0.877278
CHAN A3 (5V): 0.254058
CHAN B0 (3.3V): 0.118602
CHAN B1 (3.15aV): 0.154122
CHAN B2 (3.15bV): 0.164741
CHAN B3 (GND): -0.005332
OPEN: 0.012078
Full Scale: +/- 1 mA
2025-03-05T21:23:07.601Z,1741209787.601 [DataOverHttps](INFO): Sending 813 bytes from file Logs/20250305T202558/Express0029.lzma
2025-03-05T21:23:08.602Z,1741209788.602 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0029.lzma.bak
2025-03-05T21:23:08.602Z,1741209788.602 [DataOverHttps](INFO): SBD MOMSN=24098520
2025-03-05T21:23:11.177Z,1741209791.177 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:23:11.177Z,1741209791.177 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:23:11.177Z,1741209791.177 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:23:17.633Z,1741209797.633 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:23:18.023Z,1741209798.023 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:23:28.927Z,1741209808.927 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.002807
CHAN A1 (24V): 0.017552
CHAN A2 (12V): 0.000625
CHAN A3 (5V): -0.003114
CHAN B0 (3.3V): -0.002614
CHAN B1 (3.15aV): -0.002806
CHAN B2 (3.15bV): -0.002402
CHAN B3 (GND): -0.003968
OPEN: 0.006954
Full Scale: +/- 1 mA
2025-03-05T21:24:01.989Z,1741209841.989 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:24:02.075Z,1741209842.075 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:24:12.965Z,1741209852.965 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.868684
CHAN A1 (24V): 0.800909
CHAN A2 (12V): 0.882844
CHAN A3 (5V): 0.276971
CHAN B0 (3.3V): 0.122450
CHAN B1 (3.15aV): 0.160506
CHAN B2 (3.15bV): 0.178904
CHAN B3 (GND): -0.005374
OPEN: 0.011997
Full Scale: +/- 1 mA
2025-03-05T21:25:33.338Z,1741209933.338 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,0000000000653,+00000,A
2025-03-05T21:25:33.338Z,1741209933.338 [DVL_micro](ERROR): Failed to parse:
:TS,0000000000653,+00000,A
2025-03-05T21:25:43.545Z,1741209943.545 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:25:43.891Z,1741209943.891 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:25:54.794Z,1741209954.794 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.005659
CHAN A1 (24V): 0.021554
CHAN A2 (12V): 0.001701
CHAN A3 (5V): -0.002251
CHAN B0 (3.3V): -0.001873
CHAN B1 (3.15aV): -0.002141
CHAN B2 (3.15bV): -0.002208
CHAN B3 (GND): -0.003697
OPEN: 0.007019
Full Scale: +/- 1 mA
2025-03-05T21:26:13.731Z,1741209973.731 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-03-05T21:26:13.731Z,1741209973.731 [DropWeight] Hardware Fault, FailCount= 1
2025-03-05T21:26:13.732Z,1741209973.732 [DropWeight](ERROR): Hardware Fault
2025-03-05T21:26:13.750Z,1741209973.750 [CommandExec](FAULT): Scheduling is paused
2025-03-05T21:26:13.751Z,1741209973.751 [CBIT](INFO): Critical error at 20250305T212613
2025-03-05T21:26:13.751Z,1741209973.751 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-03-05T21:26:13.753Z,1741209973.753 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-03-05T21:26:13.754Z,1741209973.754 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-03-05T21:26:14.164Z,1741209974.164 [CBIT](INFO): Critical error at 20250305T212613
2025-03-05T21:27:21.485Z,1741210041.485 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:27:21.625Z,1741210041.625 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:27:32.539Z,1741210052.539 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.004669
CHAN A1 (24V): 0.020418
CHAN A2 (12V): 0.001941
CHAN A3 (5V): -0.001960
CHAN B0 (3.3V): -0.001700
CHAN B1 (3.15aV): -0.001779
CHAN B2 (3.15bV): -0.001720
CHAN B3 (GND): -0.003729
OPEN: 0.006948
Full Scale: +/- 1 mA
2025-03-05T21:27:43.421Z,1741210063.421 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T21:28:11.719Z,1741210091.719 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:28:11.719Z,1741210091.719 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:28:11.719Z,1741210091.719 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:28:11.719Z,1741210091.719 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:28:12.122Z,1741210092.122 [Default:CheckIn:D] Stopped
2025-03-05T21:28:12.122Z,1741210092.122 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.977450 min
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn:E] Stopped
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn] Stopped
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn](INFO): Running loop #10
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn] Running Loop=10
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:28:12.533Z,1741210092.533 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:28:14.535Z,1741210094.535 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212810.00,A,3648.16819,N,12147.28518,W,0.350,0.00,050325,,,A*7A
2025-03-05T21:28:14.537Z,1741210094.537 [NAL9602](INFO): GPS fix at 20250305T212810: (36.802803, -121.788086)
2025-03-05T21:28:14.572Z,1741210094.572 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:28:14.573Z,1741210094.573 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:28:21.893Z,1741210101.893 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20250305T202558/Courier0031.lzma
2025-03-05T21:28:22.894Z,1741210102.894 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0031.lzma.bak
2025-03-05T21:28:22.894Z,1741210102.894 [DataOverHttps](INFO): SBD MOMSN=24099951
2025-03-05T21:28:42.941Z,1741210122.941 [DataOverHttps](INFO): Sending 646 bytes from file Logs/20250305T202558/Express0032.lzma
2025-03-05T21:28:43.942Z,1741210123.942 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0032.lzma.bak
2025-03-05T21:28:43.942Z,1741210123.942 [DataOverHttps](INFO): SBD MOMSN=24099956
2025-03-05T21:28:46.857Z,1741210126.857 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:28:46.885Z,1741210126.885 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:28:46.885Z,1741210126.885 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:28:46.885Z,1741210126.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:30:48.549Z,1741210248.549 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadA4
2025-03-05T21:33:47.555Z,1741210427.555 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:33:47.555Z,1741210427.555 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:33:47.555Z,1741210427.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:33:47.556Z,1741210427.556 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:33:47.954Z,1741210427.954 [Default:CheckIn:D] Stopped
2025-03-05T21:33:47.954Z,1741210427.954 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:33:48.389Z,1741210428.389 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.574650 min
2025-03-05T21:33:48.389Z,1741210428.389 [Default:CheckIn:E] Stopped
2025-03-05T21:33:48.389Z,1741210428.389 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:33:48.389Z,1741210428.389 [Default:CheckIn] Stopped
2025-03-05T21:33:48.390Z,1741210428.390 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:33:48.390Z,1741210428.390 [Default:CheckIn](INFO): Running loop #11
2025-03-05T21:33:48.390Z,1741210428.390 [Default:CheckIn] Running Loop=11
2025-03-05T21:33:48.390Z,1741210428.390 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:33:48.390Z,1741210428.390 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:33:50.367Z,1741210430.367 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213346.00,A,3648.16663,N,12147.28022,W,0.369,0.00,050325,,,A*76
2025-03-05T21:33:50.369Z,1741210430.369 [NAL9602](INFO): GPS fix at 20250305T213346: (36.802777, -121.788004)
2025-03-05T21:33:50.380Z,1741210430.380 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:33:50.380Z,1741210430.380 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:33:59.111Z,1741210439.111 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0034.lzma
2025-03-05T21:34:00.114Z,1741210440.114 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0034.lzma.bak
2025-03-05T21:34:00.114Z,1741210440.114 [DataOverHttps](INFO): SBD MOMSN=24100930
2025-03-05T21:34:04.805Z,1741210444.805 [CommandExec](IMPORTANT): got command gfscan
2025-03-05T21:34:04.963Z,1741210444.963 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:34:15.930Z,1741210455.930 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.000715
CHAN A1 (24V): 0.011334
CHAN A2 (12V): -0.004640
CHAN A3 (5V): -0.007372
CHAN B0 (3.3V): -0.006160
CHAN B1 (3.15aV): -0.006134
CHAN B2 (3.15bV): -0.006202
CHAN B3 (GND): -0.007383
OPEN: -0.039584
Full Scale: +/- 1 mA
2025-03-05T21:34:18.676Z,1741210458.676 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20250305T202558/Express0035.lzma
2025-03-05T21:34:19.678Z,1741210459.678 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0035.lzma.bak
2025-03-05T21:34:19.678Z,1741210459.678 [DataOverHttps](INFO): SBD MOMSN=24101390
2025-03-05T21:34:21.078Z,1741210461.078 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-05T21:34:21.160Z,1741210461.160 [NAL9602](ERROR): received:
+CSQ:0
OK812, 0, 0, 0, 0
OK
2025-03-05T21:34:22.716Z,1741210462.716 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:34:22.716Z,1741210462.716 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:34:22.716Z,1741210462.716 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:34:36.201Z,1741210476.201 [CommandExec](IMPORTANT): got command ibit
2025-03-05T21:34:36.490Z,1741210476.490 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-03-05T21:34:36.490Z,1741210476.490 [IBIT](IMPORTANT): Beginning control surface checks.
2025-03-05T21:34:36.497Z,1741210476.497 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-05T21:34:47.363Z,1741210487.363 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.001656
CHAN A1 (24V): 0.015327
CHAN A2 (12V): -0.001243
CHAN A3 (5V): -0.004518
CHAN B0 (3.3V): -0.003367
CHAN B1 (3.15aV): -0.003575
CHAN B2 (3.15bV): -0.003751
CHAN B3 (GND): -0.004473
OPEN: 0.006095
Full Scale: +/- 1 mA
2025-03-05T21:36:22.751Z,1741210582.751 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 1
Latitude: 36.802776 Longitude: -121.788002
2025-03-05T21:36:23.123Z,1741210583.123 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 50.382000
Voltage: 13.677000
2025-03-05T21:36:23.123Z,1741210583.123 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-03-05T21:36:23.124Z,1741210583.124 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-03-05T21:36:23.531Z,1741210583.531 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-03-05T21:36:23.531Z,1741210583.531 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-03-05T21:36:23.531Z,1741210583.531 [IBIT](IMPORTANT): Pressure:10.299036 PSI
2025-03-05T21:36:23.532Z,1741210583.532 [IBIT](IMPORTANT): Humidity:5.829569 %
2025-03-05T21:36:23.949Z,1741210583.949 [IBIT](IMPORTANT): Vehicle Pitch:-2.392782 degrees
2025-03-05T21:36:23.949Z,1741210583.949 [IBIT](IMPORTANT): Vehicle Roll:-12.610876 degrees
2025-03-05T21:36:23.949Z,1741210583.949 [IBIT](IMPORTANT): Vehicle Heading:207.625641 degrees
2025-03-05T21:36:24.317Z,1741210584.317 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-03-05T21:36:24.317Z,1741210584.317 [IBIT](IMPORTANT): buoyancyNeutral: 214.355423 cc
2025-03-05T21:36:24.318Z,1741210584.318 [IBIT](IMPORTANT): massDefault: 1.220027 cm
2025-03-05T21:36:24.318Z,1741210584.318 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2025-03-05T21:36:24.318Z,1741210584.318 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-03-05T21:36:24.318Z,1741210584.318 [IBIT](IMPORTANT): IBIT PASSED
2025-03-05T21:37:31.706Z,1741210651.706 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 15 degree
2025-03-05T21:37:31.710Z,1741210651.710 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.elevatorAngleAction" handled in the control thread.
2025-03-05T21:37:31.919Z,1741210651.919 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,Maintain_VerticalControl.massPositionAction,Maintain_VerticalControl.elevatorAngleAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-05T21:37:52.459Z,1741210672.459 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction -15 degree
2025-03-05T21:38:09.179Z,1741210689.179 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 0 degree
2025-03-05T21:38:14.641Z,1741210694.641 [NAL9602](INFO): SBD MO Status=2, MOMSN=18813, MT Status=2, MTMSN=0
2025-03-05T21:38:14.642Z,1741210694.642 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:38:16.266Z,1741210696.266 [CommandExec](IMPORTANT): got command maintain clear
2025-03-05T21:38:16.322Z,1741210696.322 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-05T21:38:36.909Z,1741210716.909 [NAL9602](INFO): SBD MO Status=0, MOMSN=18813, MT Status=0, MTMSN=0
2025-03-05T21:38:36.909Z,1741210716.909 [NAL9602](INFO): No messages in MT queue
2025-03-05T21:39:07.565Z,1741210747.565 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:39:23.316Z,1741210763.316 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:39:23.316Z,1741210763.316 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:39:23.316Z,1741210763.316 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:39:23.316Z,1741210763.316 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:39:23.723Z,1741210763.723 [Default:CheckIn:D] Stopped
2025-03-05T21:39:23.723Z,1741210763.723 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.170793 min
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn:E] Stopped
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn] Stopped
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn](INFO): Running loop #12
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn] Running Loop=12
2025-03-05T21:39:24.122Z,1741210764.122 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:39:24.123Z,1741210764.123 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:39:26.142Z,1741210766.142 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213922.00,A,3648.16939,N,12147.28650,W,0.369,310.24,050325,,,A*79
2025-03-05T21:39:26.153Z,1741210766.153 [NAL9602](INFO): GPS fix at 20250305T213922: (36.802823, -121.788108)
2025-03-05T21:39:26.191Z,1741210766.191 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:39:26.191Z,1741210766.191 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:39:34.539Z,1741210774.539 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0037.lzma
2025-03-05T21:39:35.542Z,1741210775.542 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0037.lzma.bak
2025-03-05T21:39:35.542Z,1741210775.542 [DataOverHttps](INFO): SBD MOMSN=24102330
2025-03-05T21:39:45.886Z,1741210785.886 [NAL9602](INFO): SBD MO Status=2, MOMSN=18814, MT Status=2, MTMSN=0
2025-03-05T21:39:45.886Z,1741210785.886 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:39:54.042Z,1741210794.042 [DataOverHttps](INFO): Sending 920 bytes from file Logs/20250305T202558/Express0038.lzma
2025-03-05T21:39:54.706Z,1741210794.706 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0038.lzma.bak
2025-03-05T21:39:54.706Z,1741210794.706 [DataOverHttps](INFO): SBD MOMSN=24102333
2025-03-05T21:39:55.971Z,1741210795.971 [NAL9602](INFO): SBD MO Status=0, MOMSN=18814, MT Status=0, MTMSN=0
2025-03-05T21:39:55.971Z,1741210795.971 [NAL9602](INFO): No messages in MT queue
2025-03-05T21:39:57.606Z,1741210797.606 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:39:57.606Z,1741210797.606 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:39:57.606Z,1741210797.606 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:40:26.720Z,1741210826.720 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:41:13.953Z,1741210873.953 [CBIT](INFO): Clearing failed state for component DropWeight
2025-03-05T21:41:13.953Z,1741210873.953 [DropWeight] No Fault, FailCount= 1
2025-03-05T21:42:23.029Z,1741210943.029 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-03-05T21:42:23.030Z,1741210943.030 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2025-03-05T21:42:23.033Z,1741210943.033 [BPC1](CRITICAL): Battery Capacity Below Threshold. 49.319000 Ah.
2025-03-05T21:42:23.033Z,1741210943.033 [BPC1](INFO): Received data from all battery sticks.
2025-03-05T21:42:23.054Z,1741210943.054 [CBIT](INFO): Critical error at 20250305T214223
2025-03-05T21:43:16.165Z,1741210996.165 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction -15 degree
2025-03-05T21:43:16.166Z,1741210996.166 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.elevatorAngleAction" handled in the control thread.
2025-03-05T21:43:16.423Z,1741210996.423 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.elevatorAngleAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-05T21:43:41.676Z,1741211021.676 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 15 degree
2025-03-05T21:43:57.653Z,1741211037.653 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA4
2025-03-05T21:44:19.833Z,1741211059.833 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadA4
2025-03-05T21:44:58.159Z,1741211098.159 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:44:58.159Z,1741211098.159 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:44:58.159Z,1741211098.159 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:44:58.159Z,1741211098.159 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:44:58.584Z,1741211098.584 [Default:CheckIn:D] Stopped
2025-03-05T21:44:58.584Z,1741211098.584 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:44:59.020Z,1741211099.020 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.751815 min
2025-03-05T21:44:59.020Z,1741211099.020 [Default:CheckIn:E] Stopped
2025-03-05T21:44:59.020Z,1741211099.020 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:44:59.020Z,1741211099.020 [Default:CheckIn] Stopped
2025-03-05T21:44:59.020Z,1741211099.020 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:44:59.021Z,1741211099.021 [Default:CheckIn](INFO): Running loop #13
2025-03-05T21:44:59.021Z,1741211099.021 [Default:CheckIn] Running Loop=13
2025-03-05T21:44:59.021Z,1741211099.021 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:44:59.021Z,1741211099.021 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:45:01.004Z,1741211101.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214457.00,A,3648.16665,N,12147.28104,W,0.311,310.99,050325,,,A*78
2025-03-05T21:45:01.006Z,1741211101.006 [NAL9602](INFO): GPS fix at 20250305T214457: (36.802777, -121.788017)
2025-03-05T21:45:01.066Z,1741211101.066 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:45:01.066Z,1741211101.066 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:45:10.003Z,1741211110.003 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250305T202558/Courier0040.lzma
2025-03-05T21:45:11.006Z,1741211111.006 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0040.lzma.bak
2025-03-05T21:45:11.006Z,1741211111.006 [DataOverHttps](INFO): SBD MOMSN=24103770
2025-03-05T21:45:29.832Z,1741211129.832 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20250305T202558/Express0041.lzma
2025-03-05T21:45:30.834Z,1741211130.834 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0041.lzma.bak
2025-03-05T21:45:30.834Z,1741211130.834 [DataOverHttps](INFO): SBD MOMSN=24103774
2025-03-05T21:45:33.502Z,1741211133.502 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:45:33.502Z,1741211133.502 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:45:33.503Z,1741211133.503 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:46:51.833Z,1741211211.833 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2025-03-05T21:47:22.129Z,1741211242.129 [NAL9602](INFO): SBD MO Status=2, MOMSN=18815, MT Status=2, MTMSN=0
2025-03-05T21:47:22.129Z,1741211242.129 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:49:03.538Z,1741211343.538 [NAL9602](INFO): SBD MO Status=2, MOMSN=18815, MT Status=2, MTMSN=0
2025-03-05T21:49:03.538Z,1741211343.538 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:49:43.134Z,1741211383.134 [NAL9602](INFO): SBD MO Status=2, MOMSN=18815, MT Status=2, MTMSN=0
2025-03-05T21:49:43.135Z,1741211383.135 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:50:08.597Z,1741211408.597 [NAL9602](INFO): SBD MO Status=0, MOMSN=18815, MT Status=0, MTMSN=0
2025-03-05T21:50:08.597Z,1741211408.597 [NAL9602](INFO): No messages in MT queue
2025-03-05T21:50:34.047Z,1741211434.047 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:50:34.047Z,1741211434.047 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:50:34.047Z,1741211434.047 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:50:34.052Z,1741211434.052 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:50:34.453Z,1741211434.453 [Default:CheckIn:D] Stopped
2025-03-05T21:50:34.453Z,1741211434.453 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.349626 min
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn:E] Stopped
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn] Stopped
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn](INFO): Running loop #14
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn] Running Loop=14
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:50:34.877Z,1741211434.877 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:50:36.866Z,1741211436.866 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215033.00,A,3648.16838,N,12147.28359,W,0.097,311.57,050325,,,A*7D
2025-03-05T21:50:36.869Z,1741211436.869 [NAL9602](INFO): GPS fix at 20250305T215033: (36.802806, -121.788060)
2025-03-05T21:50:36.878Z,1741211436.878 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:50:36.878Z,1741211436.878 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:50:45.595Z,1741211445.595 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0043.lzma
2025-03-05T21:50:46.598Z,1741211446.598 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0043.lzma.bak
2025-03-05T21:50:46.598Z,1741211446.598 [DataOverHttps](INFO): SBD MOMSN=24104717
2025-03-05T21:51:06.739Z,1741211466.739 [DataOverHttps](INFO): Sending 185 bytes from file Logs/20250305T202558/Express0044.lzma
2025-03-05T21:51:07.743Z,1741211467.743 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0044.lzma.bak
2025-03-05T21:51:07.743Z,1741211467.743 [DataOverHttps](INFO): SBD MOMSN=24105180
2025-03-05T21:51:09.597Z,1741211469.597 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T21:51:10.429Z,1741211470.429 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:51:10.429Z,1741211470.429 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:51:10.429Z,1741211470.429 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:52:33.793Z,1741211553.793 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB1
2025-03-05T21:52:56.933Z,1741211576.933 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadB1
2025-03-05T21:53:30.158Z,1741211610.158 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadB1
2025-03-05T21:54:17.909Z,1741211657.909 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA4
2025-03-05T21:55:12.005Z,1741211712.005 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA3
2025-03-05T21:55:26.713Z,1741211726.713 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA2
2025-03-05T21:55:30.385Z,1741211730.385 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA1
2025-03-05T21:55:48.877Z,1741211748.877 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC6
2025-03-05T21:56:05.761Z,1741211765.761 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC4
2025-03-05T21:56:11.190Z,1741211771.190 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T21:56:11.190Z,1741211771.190 [Default:CheckIn:C.Wait] Stopped
2025-03-05T21:56:11.190Z,1741211771.190 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T21:56:11.190Z,1741211771.190 [Default:CheckIn:D] Running Loop=1
2025-03-05T21:56:11.492Z,1741211771.492 [Default:CheckIn:D] Stopped
2025-03-05T21:56:11.492Z,1741211771.492 [Default:CheckIn:E] Running Loop=1
2025-03-05T21:56:11.916Z,1741211771.916 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.966951 min
2025-03-05T21:56:11.916Z,1741211771.916 [Default:CheckIn:E] Stopped
2025-03-05T21:56:11.916Z,1741211771.916 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T21:56:11.920Z,1741211771.920 [Default:CheckIn] Stopped
2025-03-05T21:56:11.920Z,1741211771.920 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T21:56:11.920Z,1741211771.920 [Default:CheckIn](INFO): Running loop #15
2025-03-05T21:56:11.920Z,1741211771.920 [Default:CheckIn] Running Loop=15
2025-03-05T21:56:11.920Z,1741211771.920 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T21:56:11.921Z,1741211771.921 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T21:56:13.913Z,1741211773.913 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215609.00,A,3648.16897,N,12147.28175,W,0.175,292.88,050325,,,A*7E
2025-03-05T21:56:13.915Z,1741211773.915 [NAL9602](INFO): GPS fix at 20250305T215609: (36.802816, -121.788029)
2025-03-05T21:56:13.925Z,1741211773.925 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T21:56:13.925Z,1741211773.925 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T21:56:22.263Z,1741211782.263 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0046.lzma
2025-03-05T21:56:23.266Z,1741211783.266 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0046.lzma.bak
2025-03-05T21:56:23.266Z,1741211783.266 [DataOverHttps](INFO): SBD MOMSN=24106124
2025-03-05T21:56:44.156Z,1741211804.156 [DataOverHttps](INFO): Sending 263 bytes from file Logs/20250305T202558/Express0047.lzma
2025-03-05T21:56:45.082Z,1741211805.082 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0047.lzma.bak
2025-03-05T21:56:45.082Z,1741211805.082 [DataOverHttps](INFO): SBD MOMSN=24106127
2025-03-05T21:56:47.856Z,1741211807.856 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T21:56:47.856Z,1741211807.856 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T21:56:47.856Z,1741211807.856 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T21:57:10.493Z,1741211830.493 [NAL9602](INFO): SBD MO Status=2, MOMSN=18816, MT Status=2, MTMSN=0
2025-03-05T21:57:10.493Z,1741211830.493 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:57:37.964Z,1741211857.964 [NAL9602](INFO): SBD MO Status=2, MOMSN=18816, MT Status=2, MTMSN=0
2025-03-05T21:57:37.965Z,1741211857.965 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:58:55.185Z,1741211935.185 [NAL9602](INFO): SBD MO Status=2, MOMSN=18816, MT Status=2, MTMSN=0
2025-03-05T21:58:55.186Z,1741211935.186 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T21:59:04.598Z,1741211944.598 [NAL9602](INFO): SBD MO Status=0, MOMSN=18816, MT Status=0, MTMSN=0
2025-03-05T21:59:04.598Z,1741211944.598 [NAL9602](INFO): No messages in MT queue
2025-03-05T21:59:35.299Z,1741211975.299 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T22:01:48.671Z,1741212108.671 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T22:01:48.671Z,1741212108.671 [Default:CheckIn:C.Wait] Stopped
2025-03-05T22:01:48.671Z,1741212108.671 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T22:01:48.672Z,1741212108.672 [Default:CheckIn:D] Running Loop=1
2025-03-05T22:01:49.042Z,1741212109.042 [Default:CheckIn:D] Stopped
2025-03-05T22:01:49.042Z,1741212109.042 [Default:CheckIn:E] Running Loop=1
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.592782 min
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn:E] Stopped
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn] Stopped
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn](INFO): Running loop #16
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn] Running Loop=16
2025-03-05T22:01:49.556Z,1741212109.556 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T22:01:49.557Z,1741212109.557 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T22:01:51.469Z,1741212111.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220147.00,A,3648.16473,N,12147.28328,W,0.078,198.58,050325,,,A*71
2025-03-05T22:01:51.488Z,1741212111.488 [NAL9602](INFO): GPS fix at 20250305T220147: (36.802746, -121.788055)
2025-03-05T22:01:51.503Z,1741212111.503 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T22:01:51.504Z,1741212111.504 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T22:01:59.923Z,1741212119.923 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0049.lzma
2025-03-05T22:02:00.926Z,1741212120.926 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0049.lzma.bak
2025-03-05T22:02:00.926Z,1741212120.926 [DataOverHttps](INFO): SBD MOMSN=24106605
2025-03-05T22:02:01.193Z,1741212121.193 [CommandExec](IMPORTANT): got command ! echo 0 > /dev/loadB1
2025-03-05T22:02:20.105Z,1741212140.105 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20250305T202558/Express0050.lzma
2025-03-05T22:02:21.107Z,1741212141.107 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0050.lzma.bak
2025-03-05T22:02:21.107Z,1741212141.107 [DataOverHttps](INFO): SBD MOMSN=24106608
2025-03-05T22:02:23.919Z,1741212143.919 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T22:02:23.919Z,1741212143.919 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T22:02:23.919Z,1741212143.919 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T22:05:12.393Z,1741212312.393 [NAL9602](INFO): SBD MO Status=2, MOMSN=18817, MT Status=2, MTMSN=0
2025-03-05T22:05:12.393Z,1741212312.393 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T22:05:52.774Z,1741212352.774 [NAL9602](INFO): SBD MO Status=2, MOMSN=18817, MT Status=2, MTMSN=0
2025-03-05T22:05:52.774Z,1741212352.774 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T22:06:53.790Z,1741212413.790 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T22:07:24.514Z,1741212444.514 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T22:07:24.582Z,1741212444.582 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T22:07:24.582Z,1741212444.582 [Default:CheckIn:C.Wait] Stopped
2025-03-05T22:07:24.582Z,1741212444.582 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T22:07:24.583Z,1741212444.583 [Default:CheckIn:D] Running Loop=1
2025-03-05T22:07:24.906Z,1741212444.906 [Default:CheckIn:D] Stopped
2025-03-05T22:07:24.906Z,1741212444.906 [Default:CheckIn:E] Running Loop=1
2025-03-05T22:07:25.306Z,1741212445.306 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.190503 min
2025-03-05T22:07:25.306Z,1741212445.306 [Default:CheckIn:E] Stopped
2025-03-05T22:07:25.306Z,1741212445.306 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T22:07:25.307Z,1741212445.307 [Default:CheckIn] Stopped
2025-03-05T22:07:25.307Z,1741212445.307 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T22:07:25.307Z,1741212445.307 [Default:CheckIn](INFO): Running loop #17
2025-03-05T22:07:25.307Z,1741212445.307 [Default:CheckIn] Running Loop=17
2025-03-05T22:07:25.307Z,1741212445.307 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T22:07:25.307Z,1741212445.307 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T22:07:27.321Z,1741212447.321 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220723.00,A,3648.16603,N,12147.28461,W,0.117,267.90,050325,,,A*75
2025-03-05T22:07:27.323Z,1741212447.323 [NAL9602](INFO): GPS fix at 20250305T220723: (36.802767, -121.788077)
2025-03-05T22:07:27.333Z,1741212447.333 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T22:07:27.333Z,1741212447.333 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T22:07:35.763Z,1741212455.763 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0052.lzma
2025-03-05T22:07:36.767Z,1741212456.767 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0052.lzma.bak
2025-03-05T22:07:36.767Z,1741212456.767 [DataOverHttps](INFO): SBD MOMSN=24106647
2025-03-05T22:07:55.532Z,1741212475.532 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20250305T202558/Express0053.lzma
2025-03-05T22:07:56.534Z,1741212476.534 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0053.lzma.bak
2025-03-05T22:07:56.534Z,1741212476.534 [DataOverHttps](INFO): SBD MOMSN=24106650
2025-03-05T22:07:58.046Z,1741212478.046 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-05T22:07:58.128Z,1741212478.128 [NAL9602](ERROR): received:
+CSQ:0
OK817, 2, 0, 0, 0
OK
2025-03-05T22:07:59.699Z,1741212479.699 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T22:07:59.708Z,1741212479.708 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T22:07:59.708Z,1741212479.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T22:08:33.985Z,1741212513.985 [NAL9602](INFO): SBD MO Status=2, MOMSN=18817, MT Status=2, MTMSN=0
2025-03-05T22:08:33.986Z,1741212513.986 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T22:08:53.478Z,1741212533.478 [DVL_micro](ERROR): Failed to parse:
:SA,-02.72,-03.06,318.8
2025-03-05T22:10:55.043Z,1741212655.043 [NAL9602](INFO): SBD MO Status=2, MOMSN=18817, MT Status=2, MTMSN=0
2025-03-05T22:10:55.044Z,1741212655.044 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T22:11:15.245Z,1741212675.245 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-03-05T22:11:15.245Z,1741212675.245 [DropWeight] Hardware Fault, FailCount= 1
2025-03-05T22:11:15.245Z,1741212675.245 [DropWeight](ERROR): Hardware Fault
2025-03-05T22:11:15.338Z,1741212675.338 [CBIT](INFO): Critical error at 20250305T221115
2025-03-05T22:11:15.344Z,1741212675.344 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-03-05T22:11:15.345Z,1741212675.345 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-03-05T22:11:15.755Z,1741212675.755 [CBIT](INFO): Critical error at 20250305T221115
2025-03-05T22:12:29.571Z,1741212749.571 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T22:13:00.277Z,1741212780.277 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T22:13:00.347Z,1741212780.347 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T22:13:00.356Z,1741212780.356 [Default:CheckIn:C.Wait] Stopped
2025-03-05T22:13:00.356Z,1741212780.356 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T22:13:00.356Z,1741212780.356 [Default:CheckIn:D] Running Loop=1
2025-03-05T22:13:00.740Z,1741212780.740 [Default:CheckIn:D] Stopped
2025-03-05T22:13:00.740Z,1741212780.740 [Default:CheckIn:E] Running Loop=1
2025-03-05T22:13:01.122Z,1741212781.122 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.787752 min
2025-03-05T22:13:01.122Z,1741212781.122 [Default:CheckIn:E] Stopped
2025-03-05T22:13:01.122Z,1741212781.122 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T22:13:01.122Z,1741212781.122 [Default:CheckIn] Stopped
2025-03-05T22:13:01.122Z,1741212781.122 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T22:13:01.123Z,1741212781.123 [Default:CheckIn](INFO): Running loop #18
2025-03-05T22:13:01.123Z,1741212781.123 [Default:CheckIn] Running Loop=18
2025-03-05T22:13:01.123Z,1741212781.123 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T22:13:01.123Z,1741212781.123 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T22:13:03.110Z,1741212783.110 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221259.00,A,3648.16538,N,12147.28230,W,0.233,173.06,050325,,,A*79
2025-03-05T22:13:03.112Z,1741212783.112 [NAL9602](INFO): GPS fix at 20250305T221259: (36.802756, -121.788038)
2025-03-05T22:13:03.123Z,1741212783.123 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T22:13:03.123Z,1741212783.123 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T22:13:11.015Z,1741212791.015 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250305T202558/Courier0055.lzma
2025-03-05T22:13:12.018Z,1741212792.018 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0055.lzma.bak
2025-03-05T22:13:12.018Z,1741212792.018 [DataOverHttps](INFO): SBD MOMSN=24108041
2025-03-05T22:13:30.824Z,1741212810.824 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250305T202558/Express0056.lzma
2025-03-05T22:13:31.826Z,1741212811.826 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0056.lzma.bak
2025-03-05T22:13:31.826Z,1741212811.826 [DataOverHttps](INFO): SBD MOMSN=24108048
2025-03-05T22:13:33.818Z,1741212813.818 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-05T22:13:33.904Z,1741212813.904 [NAL9602](ERROR): received:
+CSQ:0
OK817, 2, 0, 0, 0
OK
2025-03-05T22:13:34.688Z,1741212814.688 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T22:13:34.688Z,1741212814.688 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T22:13:34.688Z,1741212814.688 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T22:16:15.061Z,1741212975.061 [NAL9602](INFO): SBD MO Status=2, MOMSN=18817, MT Status=2, MTMSN=0
2025-03-05T22:16:15.062Z,1741212975.062 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-05T22:16:55.873Z,1741213015.873 [NAL9602](INFO): SBD MO Status=0, MOMSN=18817, MT Status=0, MTMSN=0
2025-03-05T22:16:55.873Z,1741213015.873 [NAL9602](INFO): No messages in MT queue
2025-03-05T22:17:26.579Z,1741213046.579 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T22:18:35.302Z,1741213115.302 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T22:18:35.303Z,1741213115.303 [Default:CheckIn:C.Wait] Stopped
2025-03-05T22:18:35.303Z,1741213115.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T22:18:35.303Z,1741213115.303 [Default:CheckIn:D] Running Loop=1
2025-03-05T22:18:35.690Z,1741213115.690 [Default:CheckIn:D] Stopped
2025-03-05T22:18:35.690Z,1741213115.690 [Default:CheckIn:E] Running Loop=1
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.370256 min
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn:E] Stopped
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn] Stopped
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn](INFO): Running loop #19
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn] Running Loop=19
2025-03-05T22:18:36.111Z,1741213116.111 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T22:18:36.112Z,1741213116.112 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T22:18:38.115Z,1741213118.115 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221834.00,A,3648.16243,N,12147.28488,W,0.272,193.56,050325,,,A*78
2025-03-05T22:18:38.118Z,1741213118.118 [NAL9602](INFO): GPS fix at 20250305T221834: (36.802707, -121.788081)
2025-03-05T22:18:38.127Z,1741213118.127 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T22:18:38.127Z,1741213118.127 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T22:18:46.199Z,1741213126.199 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0058.lzma
2025-03-05T22:18:47.202Z,1741213127.202 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0058.lzma.bak
2025-03-05T22:18:47.202Z,1741213127.202 [DataOverHttps](INFO): SBD MOMSN=24108985
2025-03-05T22:19:07.452Z,1741213147.452 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250305T202558/Express0059.lzma
2025-03-05T22:19:08.454Z,1741213148.454 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0059.lzma.bak
2025-03-05T22:19:08.454Z,1741213148.454 [DataOverHttps](INFO): SBD MOMSN=24109445
2025-03-05T22:19:11.291Z,1741213151.291 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T22:19:11.291Z,1741213151.291 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T22:19:11.291Z,1741213151.291 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T22:19:59.115Z,1741213199.115 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadC7
2025-03-05T22:20:07.393Z,1741213207.393 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadC6
2025-03-05T22:20:22.135Z,1741213222.135 [CommandExec](IMPORTANT): got command ! echo d > /dev/loadC5
2025-03-05T22:23:40.731Z,1741213420.731 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-05T22:24:11.438Z,1741213451.438 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-05T22:24:11.858Z,1741213451.858 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-05T22:24:11.858Z,1741213451.858 [Default:CheckIn:C.Wait] Stopped
2025-03-05T22:24:11.858Z,1741213451.858 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T22:24:11.858Z,1741213451.858 [Default:CheckIn:D] Running Loop=1
2025-03-05T22:24:12.255Z,1741213452.255 [Default:CheckIn:D] Stopped
2025-03-05T22:24:12.255Z,1741213452.255 [Default:CheckIn:E] Running Loop=1
2025-03-05T22:24:12.678Z,1741213452.678 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.979655 min
2025-03-05T22:24:12.678Z,1741213452.678 [Default:CheckIn:E] Stopped
2025-03-05T22:24:12.678Z,1741213452.678 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-05T22:24:12.678Z,1741213452.678 [Default:CheckIn] Stopped
2025-03-05T22:24:12.678Z,1741213452.678 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T22:24:12.679Z,1741213452.679 [Default:CheckIn](INFO): Running loop #20
2025-03-05T22:24:12.679Z,1741213452.679 [Default:CheckIn] Running Loop=20
2025-03-05T22:24:12.679Z,1741213452.679 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-05T22:24:12.679Z,1741213452.679 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-05T22:24:14.679Z,1741213454.679 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222410.00,A,3648.16324,N,12147.27962,W,0.330,193.56,050325,,,A*70
2025-03-05T22:24:14.682Z,1741213454.682 [NAL9602](INFO): GPS fix at 20250305T222410: (36.802721, -121.787994)
2025-03-05T22:24:14.691Z,1741213454.691 [Default:CheckIn:Read_GPS] Stopped
2025-03-05T22:24:14.692Z,1741213454.692 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-05T22:24:23.043Z,1741213463.043 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250305T202558/Courier0061.lzma
2025-03-05T22:24:24.046Z,1741213464.046 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Courier0061.lzma.bak
2025-03-05T22:24:24.046Z,1741213464.046 [DataOverHttps](INFO): SBD MOMSN=24109956
2025-03-05T22:24:45.432Z,1741213485.432 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-05T22:24:45.512Z,1741213485.512 [NAL9602](ERROR): received:
+CSQ:0
OK817, 0, 0, 0, 0
OK
2025-03-05T22:24:45.804Z,1741213485.804 [DataOverHttps](INFO): Sending 282 bytes from file Logs/20250305T202558/Express0062.lzma
2025-03-05T22:24:46.806Z,1741213486.806 [DataOverHttps](INFO): Moved sent file to Logs/20250305T202558/Express0062.lzma.bak
2025-03-05T22:24:46.806Z,1741213486.806 [DataOverHttps](INFO): SBD MOMSN=24109959
2025-03-05T22:24:49.908Z,1741213489.908 [Default:CheckIn:Read_Iridium] Stopped
2025-03-05T22:24:49.908Z,1741213489.908 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-05T22:24:49.908Z,1741213489.908 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-05T22:26:15.570Z,1741213575.570 [CBIT](INFO): Clearing failed state for component DropWeight
2025-03-05T22:26:15.570Z,1741213575.570 [DropWeight] No Fault, FailCount= 1
2025-03-05T22:26:16.722Z,1741213576.722 [Sonardyne_Nano](INFO): Battery at maximum, disabling charging
2025-03-05T22:26:35.105Z,1741213595.105 [CommandExec](IMPORTANT): got command restart application
2025-03-05T22:26:36.108Z,1741213596.108 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:36.108Z,1741213596.108 [CommandExec](INFO): Uninitializing the command executive.
2025-03-05T22:26:36.108Z,1741213596.108 [CommandExec](INFO): Uninitializing the command scheduler.
2025-03-05T22:26:36.108Z,1741213596.108 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:36.292Z,1741213596.292 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2025-03-05T22:26:36.293Z,1741213596.293 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-03-05T22:26:36.293Z,1741213596.293 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:36.293Z,1741213596.293 [NavChartDb](INFO): Join timeout helper Thread ID is 8432
2025-03-05T22:26:36.692Z,1741213596.692 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:36.692Z,1741213596.692 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:36.716Z,1741213596.716 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-03-05T22:26:36.716Z,1741213596.716 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:36.716Z,1741213596.716 [Radio_Surface](INFO): Join timeout helper Thread ID is 8433
2025-03-05T22:26:37.053Z,1741213597.053 [Radio_Surface](INFO): Powering down
2025-03-05T22:26:37.057Z,1741213597.057 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:37.058Z,1741213597.058 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:37.064Z,1741213597.064 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-03-05T22:26:37.064Z,1741213597.064 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:37.064Z,1741213597.064 [Onboard](INFO): Join timeout helper Thread ID is 8434
2025-03-05T22:26:40.976Z,1741213600.976 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:40.977Z,1741213600.977 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:40.984Z,1741213600.984 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-03-05T22:26:40.984Z,1741213600.984 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:40.985Z,1741213600.985 [DataOverHttps](INFO): Join timeout helper Thread ID is 8445
2025-03-05T22:26:41.844Z,1741213601.844 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:41.847Z,1741213601.847 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:41.852Z,1741213601.852 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler
2025-03-05T22:26:41.852Z,1741213601.852 [DATMMP ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:41.852Z,1741213601.852 [DATMMP](INFO): Join timeout helper Thread ID is 8446
2025-03-05T22:26:42.036Z,1741213602.036 [DATMMP](INFO): Stop
2025-03-05T22:26:42.036Z,1741213602.036 [DATMMP](INFO): uninitialize
2025-03-05T22:26:42.036Z,1741213602.036 [DATMMP](INFO): Powering down
2025-03-05T22:26:42.109Z,1741213602.109 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:42.109Z,1741213602.109 [DATMMP](INFO): uninitialize
2025-03-05T22:26:42.109Z,1741213602.109 [DATMMP](INFO): Powering down
2025-03-05T22:26:42.110Z,1741213602.110 [DATMMP ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:42.121Z,1741213602.121 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2025-03-05T22:26:42.121Z,1741213602.121 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:42.121Z,1741213602.121 [BackseatComponent](INFO): Join timeout helper Thread ID is 8447
2025-03-05T22:26:42.224Z,1741213602.224 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:42.224Z,1741213602.224 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:42.237Z,1741213602.237 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2025-03-05T22:26:42.237Z,1741213602.237 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:42.237Z,1741213602.237 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8450
2025-03-05T22:26:42.488Z,1741213602.488 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:42.488Z,1741213602.488 [WetLabsBB2FL](INFO): Powering down
2025-03-05T22:26:42.489Z,1741213602.489 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:42.496Z,1741213602.496 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2025-03-05T22:26:42.497Z,1741213602.497 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:42.497Z,1741213602.497 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8452
2025-03-05T22:26:43.240Z,1741213603.240 [CTD_Seabird](INFO): Powering down
2025-03-05T22:26:43.252Z,1741213603.252 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:43.252Z,1741213603.252 [CTD_Seabird](INFO): Powering down
2025-03-05T22:26:43.264Z,1741213603.264 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:43.285Z,1741213603.285 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2025-03-05T22:26:43.285Z,1741213603.285 [logger ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:43.285Z,1741213603.285 [logger](INFO): Join timeout helper Thread ID is 8460
2025-03-05T22:26:43.350Z,1741213603.350 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:43.350Z,1741213603.350 [logger ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:43.361Z,1741213603.361 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2025-03-05T22:26:43.361Z,1741213603.361 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:43.361Z,1741213603.361 [CommandLine](INFO): Join timeout helper Thread ID is 8461
2025-03-05T22:26:43.400Z,1741213603.400 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:43.400Z,1741213603.400 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:43.402Z,1741213603.402 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2025-03-05T22:26:43.402Z,1741213603.402 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:43.402Z,1741213603.402 [CommandExec](INFO): Join timeout helper Thread ID is 8462
2025-03-05T22:26:43.403Z,1741213603.403 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2025-03-05T22:26:43.440Z,1741213603.440 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:43.440Z,1741213603.440 [controlThread](INFO): Join timeout helper Thread ID is 8463
2025-03-05T22:26:43.764Z,1741213603.764 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-05T22:26:43.764Z,1741213603.764 [controlThread](DEBUG): Uninitializing ControlThread
2025-03-05T22:26:43.766Z,1741213603.766 [AHRS_M2](INFO): Powering down
2025-03-05T22:26:43.932Z,1741213603.932 [DVL_micro](INFO): Powering down
2025-03-05T22:26:43.933Z,1741213603.933 [NAL9602](INFO): Powering down
2025-03-05T22:26:43.934Z,1741213603.934 [Sonardyne_Nano](INFO): Powering down
2025-03-05T22:26:44.053Z,1741213604.053 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2025-03-05T22:26:44.053Z,1741213604.053 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2025-03-05T22:26:44.054Z,1741213604.054 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2025-03-05T22:26:44.054Z,1741213604.054 [MissionManager](INFO): Uninitializing Mission Default
2025-03-05T22:26:44.054Z,1741213604.054 [Default] Stopped
2025-03-05T22:26:44.054Z,1741213604.055 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-05T22:26:44.055Z,1741213604.055 [Default:B.GoToSurface] Stopped
2025-03-05T22:26:44.055Z,1741213604.055 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-05T22:26:44.055Z,1741213604.055 [Default:CheckIn] Stopped
2025-03-05T22:26:44.055Z,1741213604.055 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-05T22:26:44.055Z,1741213604.055 [Default:CheckIn:C.Wait] Stopped
2025-03-05T22:26:44.055Z,1741213604.055 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-05T22:26:44.058Z,1741213604.058 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2025-03-05T22:26:44.058Z,1741213604.058 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2025-03-05T22:26:44.058Z,1741213604.058 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2025-03-05T22:26:44.059Z,1741213604.059 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2025-03-05T22:26:44.059Z,1741213604.059 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-03-05T22:26:44.059Z,1741213604.059 [BuoyancyServo](INFO): Powering down
2025-03-05T22:26:44.072Z,1741213604.072 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-03-05T22:26:44.072Z,1741213604.072 [ElevatorServo](INFO): Powering down
2025-03-05T22:26:44.073Z,1741213604.073 [MassServo](DEBUG): Uninitialize Mass Servo.
2025-03-05T22:26:44.073Z,1741213604.073 [MassServo](INFO): Powering down
2025-03-05T22:26:44.074Z,1741213604.074 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2025-03-05T22:26:44.074Z,1741213604.074 [RudderServo](INFO): Powering down
2025-03-05T22:26:44.075Z,1741213604.075 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-03-05T22:26:44.075Z,1741213604.075 [ThrusterHE](INFO): Powering down
2025-03-05T22:26:44.077Z,1741213604.077 [SBIT](DEBUG): Uninitialize SBIT Component.
2025-03-05T22:26:44.077Z,1741213604.077 [IBIT](DEBUG): Uninitialize IBIT Component.
2025-03-05T22:26:44.077Z,1741213604.077 [CBIT](DEBUG): Uninitialize CBIT Component.
2025-03-05T22:26:44.077Z,1741213604.077 [CBIT](DEBUG): Powering off loads.
2025-03-05T22:26:44.092Z,1741213604.092 [CBIT](DEBUG): Disabling WDT.
2025-03-05T22:26:44.104Z,1741213604.104 [CBIT](DEBUG): Opening all GF detection circuits.
2025-03-05T22:26:44.105Z,1741213604.105 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.173Z,1741213604.173 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.188Z,1741213604.188 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.293Z,1741213604.293 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.295Z,1741213604.295 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.303Z,1741213604.303 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.309Z,1741213604.309 [DATMMP ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.351Z,1741213604.351 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.407Z,1741213604.407 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-03-05T22:26:44.482Z,1741213604.482 [logger ThreadHandler](INFO): Thread cancelled.