2025-01-31T05:14:04.938Z,1738300444.938 [Supervisor](DEBUG): Initializing supervisor.
2025-01-31T05:14:04.942Z,1738300444.942 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-01-31T05:14:04.942Z,1738300444.942 [SyncHandler](INFO): Protected caller Thread ID is 837
2025-01-31T05:14:04.943Z,1738300444.943 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-01-31T05:14:04.944Z,1738300444.944 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-01-31T05:14:04.944Z,1738300444.944 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838
2025-01-31T05:14:04.948Z,1738300444.948 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-01-31T05:14:04.965Z,1738300444.965 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-01-31T05:14:04.966Z,1738300444.966 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-01-31T05:14:04.966Z,1738300444.966 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839
2025-01-31T05:14:04.971Z,1738300444.971 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-01-31T05:14:04.972Z,1738300444.972 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-01-31T05:14:04.972Z,1738300444.972 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840
2025-01-31T05:14:04.974Z,1738300444.974 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-01-31T05:14:04.975Z,1738300444.975 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-01-31T05:14:04.975Z,1738300444.975 [logger ThreadHandler](INFO): Protected caller Thread ID is 841
2025-01-31T05:14:04.979Z,1738300444.979 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-01-31T05:14:04.979Z,1738300444.979 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-01-31T05:14:04.983Z,1738300444.983 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-01-31T05:14:05.365Z,1738300445.365 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-01-31T05:14:05.367Z,1738300445.367 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-01-31T05:14:05.463Z,1738300445.463 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-01-31T05:14:05.585Z,1738300445.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-01-31T05:14:05.587Z,1738300445.587 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-01-31T05:14:05.748Z,1738300445.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-01-31T05:14:05.750Z,1738300445.750 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-01-31T05:14:06.134Z,1738300446.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-01-31T05:14:06.136Z,1738300446.136 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-01-31T05:14:06.247Z,1738300446.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-01-31T05:14:06.248Z,1738300446.248 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-01-31T05:14:06.710Z,1738300446.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-01-31T05:14:06.711Z,1738300446.711 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-01-31T05:14:06.949Z,1738300446.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-01-31T05:14:06.950Z,1738300446.950 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-01-31T05:14:07.043Z,1738300447.043 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-01-31T05:14:07.309Z,1738300447.309 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-01-31T05:14:07.310Z,1738300447.310 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-01-31T05:14:07.557Z,1738300447.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-01-31T05:14:07.559Z,1738300447.559 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-01-31T05:14:08.139Z,1738300448.139 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-01-31T05:14:08.139Z,1738300448.139 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-01-31T05:14:08.384Z,1738300448.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-01-31T05:14:08.386Z,1738300448.386 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-01-31T05:14:08.706Z,1738300448.706 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-01-31T05:14:08.707Z,1738300448.707 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-01-31T05:14:09.654Z,1738300449.654 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-01-31T05:14:09.656Z,1738300449.656 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-01-31T05:14:10.277Z,1738300450.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-01-31T05:14:10.279Z,1738300450.279 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/
2025-01-31T05:14:10.281Z,1738300450.281 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg
2025-01-31T05:14:10.395Z,1738300450.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg
2025-01-31T05:14:10.529Z,1738300450.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg
2025-01-31T05:14:10.626Z,1738300450.626 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg
2025-01-31T05:14:10.749Z,1738300450.749 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg
2025-01-31T05:14:10.849Z,1738300450.849 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg
2025-01-31T05:14:11.132Z,1738300451.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-01-31T05:14:11.132Z,1738300451.132 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg
2025-01-31T05:14:11.258Z,1738300451.258 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg
2025-01-31T05:14:11.372Z,1738300451.372 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg
2025-01-31T05:14:11.533Z,1738300451.533 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg
2025-01-31T05:14:11.632Z,1738300451.632 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-01-31T05:14:11.657Z,1738300451.657 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-01-31T05:14:11.839Z,1738300451.839 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-01-31T05:14:11.840Z,1738300451.840 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-01-31T05:14:11.915Z,1738300451.915 [VerticalControl](DEBUG): Construct VerticalControl.
2025-01-31T05:14:11.976Z,1738300451.976 [VerticalControl] Loaded
2025-01-31T05:14:11.976Z,1738300451.976 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-01-31T05:14:11.979Z,1738300451.979 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-01-31T05:14:12.030Z,1738300452.030 [HorizontalControl] Loaded
2025-01-31T05:14:12.030Z,1738300452.030 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-01-31T05:14:12.032Z,1738300452.032 [SpeedControl](DEBUG): Construct SpeedControl.
2025-01-31T05:14:12.035Z,1738300452.035 [SpeedControl] Loaded
2025-01-31T05:14:12.036Z,1738300452.036 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-01-31T05:14:12.038Z,1738300452.038 [LoopControl](DEBUG): Construct LoopControl.
2025-01-31T05:14:12.039Z,1738300452.039 [LoopControl] Loaded
2025-01-31T05:14:12.039Z,1738300452.039 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-01-31T05:14:12.040Z,1738300452.040 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-01-31T05:14:12.040Z,1738300452.040 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-01-31T05:14:12.131Z,1738300452.131 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-01-31T05:14:12.132Z,1738300452.132 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-01-31T05:14:12.996Z,1738300452.996 [AHRS_M2] Loaded
2025-01-31T05:14:12.996Z,1738300452.996 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-01-31T05:14:13.251Z,1738300453.251 [BackseatComponent] Loaded
2025-01-31T05:14:13.251Z,1738300453.251 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-01-31T05:14:13.252Z,1738300453.252 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408B64E0
2025-01-31T05:14:13.252Z,1738300453.252 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 920
2025-01-31T05:14:13.255Z,1738300453.255 [LcmUniversalReporter] Loaded
2025-01-31T05:14:13.255Z,1738300453.255 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-01-31T05:14:14.130Z,1738300454.130 [BPC1] Loaded
2025-01-31T05:14:14.130Z,1738300454.130 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-01-31T05:14:14.274Z,1738300454.274 [DataOverHttps] Loaded
2025-01-31T05:14:14.274Z,1738300454.274 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-01-31T05:14:14.275Z,1738300454.275 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408E64E0
2025-01-31T05:14:14.275Z,1738300454.275 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 921
2025-01-31T05:14:14.299Z,1738300454.299 [Depth_Keller] Loaded
2025-01-31T05:14:14.299Z,1738300454.299 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-01-31T05:14:14.304Z,1738300454.304 [DropWeight] Loaded
2025-01-31T05:14:14.305Z,1738300454.305 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-01-31T05:14:14.371Z,1738300454.371 [NAL9602] Loaded
2025-01-31T05:14:14.372Z,1738300454.372 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-01-31T05:14:14.403Z,1738300454.403 [Onboard] Loaded
2025-01-31T05:14:14.403Z,1738300454.403 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-01-31T05:14:14.405Z,1738300454.405 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409164E0
2025-01-31T05:14:14.405Z,1738300454.405 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922
2025-01-31T05:14:14.419Z,1738300454.419 [Power24vConverter] Loaded
2025-01-31T05:14:14.420Z,1738300454.420 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-01-31T05:14:14.436Z,1738300454.436 [Radio_Surface] Loaded
2025-01-31T05:14:14.436Z,1738300454.436 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-01-31T05:14:14.437Z,1738300454.437 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409464E0
2025-01-31T05:14:14.438Z,1738300454.438 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923
2025-01-31T05:14:14.454Z,1738300454.454 [Sonardyne_Nano] Loaded
2025-01-31T05:14:14.454Z,1738300454.454 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-01-31T05:14:14.479Z,1738300454.479 [Waterlinked] Loaded
2025-01-31T05:14:14.479Z,1738300454.479 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2025-01-31T05:14:14.479Z,1738300454.479 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-01-31T05:14:14.480Z,1738300454.480 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-01-31T05:14:14.496Z,1738300454.496 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-01-31T05:14:14.498Z,1738300454.498 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-01-31T05:14:14.542Z,1738300454.542 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-01-31T05:14:14.544Z,1738300454.544 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-01-31T05:14:14.731Z,1738300454.731 [SBIT](DEBUG): Construct Startup Built In Test.
2025-01-31T05:14:14.740Z,1738300454.740 [SBIT] Loaded
2025-01-31T05:14:14.740Z,1738300454.740 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-01-31T05:14:14.743Z,1738300454.743 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-01-31T05:14:14.756Z,1738300454.756 [IBIT] Loaded
2025-01-31T05:14:14.756Z,1738300454.756 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-01-31T05:14:14.762Z,1738300454.762 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-01-31T05:14:14.868Z,1738300454.868 [CBIT] Loaded
2025-01-31T05:14:14.868Z,1738300454.868 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-01-31T05:14:14.869Z,1738300454.869 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-01-31T05:14:14.869Z,1738300454.869 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-01-31T05:14:15.362Z,1738300455.362 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-01-31T05:14:15.363Z,1738300455.363 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-01-31T05:14:15.438Z,1738300455.438 [DepthRateCalculator] Loaded
2025-01-31T05:14:15.438Z,1738300455.438 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-01-31T05:14:15.443Z,1738300455.443 [PitchRateCalculator] Loaded
2025-01-31T05:14:15.444Z,1738300455.444 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-01-31T05:14:15.454Z,1738300455.454 [SpeedCalculator] Loaded
2025-01-31T05:14:15.455Z,1738300455.455 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-01-31T05:14:15.459Z,1738300455.459 [YawRateCalculator] Loaded
2025-01-31T05:14:15.460Z,1738300455.460 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-01-31T05:14:15.479Z,1738300455.479 [ElevatorOffsetCalculator] Loaded
2025-01-31T05:14:15.479Z,1738300455.479 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-01-31T05:14:15.480Z,1738300455.480 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-01-31T05:14:15.480Z,1738300455.480 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-01-31T05:14:15.714Z,1738300455.714 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-01-31T05:14:15.715Z,1738300455.715 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-01-31T05:14:15.859Z,1738300455.859 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-01-31T05:14:15.859Z,1738300455.859 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-01-31T05:14:15.873Z,1738300455.873 [NavChart] Loaded
2025-01-31T05:14:15.874Z,1738300455.874 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-01-31T05:14:15.879Z,1738300455.879 [UniversalFixResidualReporter] Loaded
2025-01-31T05:14:15.880Z,1738300455.880 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-01-31T05:14:15.880Z,1738300455.880 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-01-31T05:14:15.882Z,1738300455.882 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-01-31T05:14:16.056Z,1738300456.056 [BuoyancyServo] Loaded
2025-01-31T05:14:16.056Z,1738300456.056 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-01-31T05:14:16.080Z,1738300456.080 [ElevatorServo] Loaded
2025-01-31T05:14:16.081Z,1738300456.081 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-01-31T05:14:16.103Z,1738300456.103 [MassServo] Loaded
2025-01-31T05:14:16.103Z,1738300456.103 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-01-31T05:14:16.125Z,1738300456.125 [RudderServo] Loaded
2025-01-31T05:14:16.125Z,1738300456.125 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-01-31T05:14:16.142Z,1738300456.142 [ThrusterHE] Loaded
2025-01-31T05:14:16.143Z,1738300456.143 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-01-31T05:14:16.143Z,1738300456.143 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-01-31T05:14:16.144Z,1738300456.144 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-01-31T05:14:16.379Z,1738300456.379 [CTD_Seabird] Loaded
2025-01-31T05:14:16.380Z,1738300456.380 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-01-31T05:14:16.381Z,1738300456.381 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BC74E0
2025-01-31T05:14:16.382Z,1738300456.382 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 925
2025-01-31T05:14:16.419Z,1738300456.419 [ESPComponent] Loaded
2025-01-31T05:14:16.419Z,1738300456.419 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-01-31T05:14:16.442Z,1738300456.442 [PAR_Licor] Loaded
2025-01-31T05:14:16.443Z,1738300456.443 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-01-31T05:14:16.489Z,1738300456.489 [WetLabsBB2FL] Loaded
2025-01-31T05:14:16.490Z,1738300456.490 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-01-31T05:14:16.491Z,1738300456.491 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BF74E0
2025-01-31T05:14:16.491Z,1738300456.491 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 926
2025-01-31T05:14:16.492Z,1738300456.492 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-01-31T05:14:16.498Z,1738300456.498 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-01-31T05:14:16.501Z,1738300456.501 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-01-31T05:14:16.512Z,1738300456.512 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-01-31T05:14:16.513Z,1738300456.513 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C274E0
2025-01-31T05:14:16.514Z,1738300456.514 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 927
2025-01-31T05:14:16.518Z,1738300456.518 [Supervisor](INFO): Main Thread ID is 828
2025-01-31T05:14:16.518Z,1738300456.518 [Supervisor](DEBUG): Running supervisor.
2025-01-31T05:14:16.519Z,1738300456.519 [CommandExec ThreadHandler](INFO): Handler Thread ID is 928
2025-01-31T05:14:16.519Z,1738300456.519 [CommandExec](INFO): Initializing the command executive.
2025-01-31T05:14:16.521Z,1738300456.521 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929
2025-01-31T05:14:16.523Z,1738300456.523 [controlThread ThreadHandler](INFO): Handler Thread ID is 930
2025-01-31T05:14:16.523Z,1738300456.523 [controlThread](DEBUG): Initializing ControlThread
2025-01-31T05:14:16.524Z,1738300456.524 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-01-31T05:14:16.526Z,1738300456.526 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-01-31T05:14:16.526Z,1738300456.526 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-01-31T05:14:16.527Z,1738300456.527 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-01-31T05:14:16.534Z,1738300456.534 [SBIT](INFO): Initialize SBIT Component.
2025-01-31T05:14:16.534Z,1738300456.534 [SBIT](IMPORTANT): git: 2025-01-28
2025-01-31T05:14:16.534Z,1738300456.534 [SBIT](INFO): git hash: 661c520267d8cf9c944d8d885edbb2392118b23e
2025-01-31T05:14:16.535Z,1738300456.535 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-01-31T05:14:16.536Z,1738300456.536 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #1 PREEMPT Tue Nov 28 15:04:22 PST 2023
2025-01-31T05:14:16.537Z,1738300456.537 [SBIT](INFO): Beginning SBIT in 73.000000 seconds.
2025-01-31T05:14:16.538Z,1738300456.538 [IBIT](INFO): Initialize IBIT Component.
2025-01-31T05:14:16.539Z,1738300456.539 [CBIT](DEBUG): Initialize CBIT Component.
2025-01-31T05:14:16.539Z,1738300456.539 [logger ThreadHandler](INFO): Handler Thread ID is 931
2025-01-31T05:14:16.552Z,1738300456.552 [CBIT](DEBUG): Initialized mux pins.
2025-01-31T05:14:16.552Z,1738300456.552 [CBIT](DEBUG): Initializing the watchdog timer.
2025-01-31T05:14:16.560Z,1738300456.560 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 932
2025-01-31T05:14:16.572Z,1738300456.572 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 933
2025-01-31T05:14:16.574Z,1738300456.574 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-01-31T05:14:16.576Z,1738300456.576 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2025-01-31T05:14:16.576Z,1738300456.576 [CBIT](DEBUG): Initializing heartbeat.
2025-01-31T05:14:16.584Z,1738300456.584 [Onboard ThreadHandler](INFO): Handler Thread ID is 934
2025-01-31T05:14:16.602Z,1738300456.602 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 935
2025-01-31T05:14:16.625Z,1738300456.625 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 936
2025-01-31T05:14:16.625Z,1738300456.625 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-01-31T05:14:16.629Z,1738300456.629 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 938
2025-01-31T05:14:16.632Z,1738300456.632 [WetLabsBB2FL](INFO): Powering up
2025-01-31T05:14:16.634Z,1738300456.634 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 940
2025-01-31T05:14:16.640Z,1738300456.640 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-01-31T05:14:16.640Z,1738300456.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-01-31T05:14:16.641Z,1738300456.641 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-01-31T05:14:16.641Z,1738300456.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-01-31T05:14:16.641Z,1738300456.641 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-01-31T05:14:16.641Z,1738300456.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-01-31T05:14:16.641Z,1738300456.641 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-01-31T05:14:16.641Z,1738300456.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-01-31T05:14:16.648Z,1738300456.648 [CBIT](DEBUG): Deactivating GF circuits.
2025-01-31T05:14:16.648Z,1738300456.648 [CBIT](DEBUG): Deactivating emergency mode.
2025-01-31T05:14:16.688Z,1738300456.688 [CBIT](DEBUG): Backplane powered.
2025-01-31T05:14:16.688Z,1738300456.688 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-01-31T05:14:16.689Z,1738300456.689 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-01-31T05:14:16.689Z,1738300456.689 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-01-31T05:14:16.689Z,1738300456.689 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-01-31T05:14:16.690Z,1738300456.690 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-01-31T05:14:16.691Z,1738300456.691 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-01-31T05:14:16.691Z,1738300456.691 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-01-31T05:14:16.697Z,1738300456.697 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-01-31T05:14:16.697Z,1738300456.697 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-01-31T05:14:16.698Z,1738300456.698 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-01-31T05:14:16.703Z,1738300456.703 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-01-31T05:14:16.786Z,1738300456.786 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="Startup">
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="StartupSatComms">
        <Sequence />
        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix />
        </ReadDatum>
        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications />
        </ReadDatum>
    </Aggregate>
</Mission>

2025-01-31T05:14:16.807Z,1738300456.807 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-01-31T05:14:16.839Z,1738300456.839 [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-01-31T05:14:16.853Z,1738300456.853 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-01-31T05:14:16.853Z,1738300456.853 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-01-31T05:14:16.868Z,1738300456.868 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-01-31T05:14:17.008Z,1738300457.008 [Radio_Surface](INFO): Powering up
2025-01-31T05:14:17.155Z,1738300457.155 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="Default">
    <DefineArg Name="ElapsedSinceDefaultStarted">
        <Units:minute />
        <Value>0</Value>
    </DefineArg>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Units:second />
            <Value>13</Value>
        </Setting>
    </Guidance:Wait>
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="CheckIn">
        <Sequence Repeat="288" />
        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M" />
            <Universal:time_fix />
        </ReadDatum>
        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence />
                    <Setting>
                        <Guidance:Execute.command />
                        <String>Burn on</String>
                    </Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications />
        </ReadDatum>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Units:minute />
                <Value>5</Value>
            </Setting>
        </Guidance:Wait>
        <Assign>
            <Sequence />
            <Arg Name="ElapsedSinceDefaultStarted" />
            <Elapsed>
                <Universal:mission_started />
            </Elapsed>
        </Assign>
        <Syslog Severity="Important">
            Default mission has been running for 
            <Arg Name="ElapsedSinceDefaultStarted" />
            <Units:minute />
        </Syslog>
    </Aggregate>
    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>
    <Guidance:Execute>
        <Sequence />
        <Setting>
            <Guidance:Execute.command />
            <String>restart logs</String>
        </Setting>
    </Guidance:Execute>
</Mission>

2025-01-31T05:14:17.173Z,1738300457.173 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-01-31T05:14:17.174Z,1738300457.174 [Default:A.Wait](DEBUG): Construct Wait.
2025-01-31T05:14:17.176Z,1738300457.176 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-01-31T05:14:17.216Z,1738300457.216 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-01-31T05:14:17.219Z,1738300457.219 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-01-31T05:14:17.241Z,1738300457.241 [Default:E.Execute](DEBUG): Construct Execute.
2025-01-31T05:14:17.256Z,1738300457.256 [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-01-31T05:14:17.261Z,1738300457.261 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,Waterlinked,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,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-01-31T05:14:17.280Z,1738300457.280 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-01-31T05:14:17.429Z,1738300457.429 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.140412 decibar, -1.132002 m
2025-01-31T05:14:17.431Z,1738300457.431 [Power24vConverter](INFO): Powering up.
2025-01-31T05:14:17.431Z,1738300457.431 [Sonardyne_Nano](INFO): Initializing.
2025-01-31T05:14:17.466Z,1738300457.466 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-01-31T05:14:17.489Z,1738300457.489 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-01-31T05:14:17.496Z,1738300457.496 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-01-31T05:14:17.497Z,1738300457.497 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-01-31T05:14:17.504Z,1738300457.504 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-01-31T05:14:17.505Z,1738300457.505 [MassServo](DEBUG): Initializing EZServoServo.
2025-01-31T05:14:17.512Z,1738300457.512 [MassServo](DEBUG): Initializing MassServo.
2025-01-31T05:14:17.513Z,1738300457.513 [RudderServo](DEBUG): Initializing EZServoServo.
2025-01-31T05:14:17.520Z,1738300457.520 [RudderServo](DEBUG): Initializing RudderServo.
2025-01-31T05:14:17.521Z,1738300457.521 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-31T05:14:17.528Z,1738300457.528 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-31T05:14:17.530Z,1738300457.530 [CommandExec](FAULT): Scheduling is paused
2025-01-31T05:14:17.531Z,1738300457.531 [CBIT](INFO): Critical error at 20250131T051416
2025-01-31T05:14:17.531Z,1738300457.531 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-01-31T05:14:18.740Z,1738300458.740 [WetLabsBB2FL](INFO): Powering down
2025-01-31T05:14:19.694Z,1738300459.694 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-01-31T05:14:20.933Z,1738300460.933 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311
2025-01-31T05:14:23.293Z,1738300463.293 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-31T05:14:23.656Z,1738300463.656 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-01-31T05:14:44.401Z,1738300484.401 [NAL9602](INFO): Powering up NAL9602
2025-01-31T05:14:51.752Z,1738300491.752 [Waterlinked](INFO): Powering down
2025-01-31T05:14:55.282Z,1738300495.282 [NAL9602](INFO): NAL9602 initialized
2025-01-31T05:15:20.735Z,1738300520.735 [NAL9602](INFO): SBD MO Status=2, MOMSN=21465, MT Status=2, MTMSN=0
2025-01-31T05:15:20.735Z,1738300520.735 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:15:24.372Z,1738300524.372 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:15:30.040Z,1738300530.040 [SBIT](IMPORTANT): Beginning Startup BIT
2025-01-31T05:15:30.045Z,1738300530.045 [CBIT](IMPORTANT): Beginning ground fault scan
2025-01-31T05:15:31.643Z,1738300531.643 [NAL9602](INFO): SBD MO Status=0, MOMSN=21465, MT Status=0, MTMSN=0
2025-01-31T05:15:31.643Z,1738300531.643 [NAL9602](INFO): No messages in MT queue
2025-01-31T05:15:32.871Z,1738300532.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,051535.00,A,3641.85881,N,12203.02570,W,0.486,340.24,310125,,,A*7A
2025-01-31T05:15:32.874Z,1738300532.874 [NAL9602](INFO): GPS fix at 20250131T051535: (36.697647, -122.050428)
2025-01-31T05:15:39.734Z,1738300539.734 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:15:41.959Z,1738300541.959 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.877606
CHAN A1 (24V): 0.843961
CHAN A2 (12V): 0.656905
CHAN A3 (5V): 0.285302
CHAN B0 (3.3V): 0.214283
CHAN B1 (3.15aV): 0.236734
CHAN B2 (3.15bV): 0.233954
CHAN B3 (GND): 0.050892
OPEN: 0.028565
Full Scale: +/- 1 mA
2025-01-31T05:15:55.896Z,1738300555.896 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:16:05.188Z,1738300565.188 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-31T05:16:11.650Z,1738300571.650 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:16:23.790Z,1738300583.790 [SBIT](IMPORTANT): SBIT PASSED
2025-01-31T05:16:23.790Z,1738300583.790 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-01-31T05:16:23.791Z,1738300583.791 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=12 count;

2025-01-31T05:16:23.791Z,1738300583.791 [SBIT](IMPORTANT): CBIT.abortDepth=305 meter;

2025-01-31T05:16:23.791Z,1738300583.791 [SBIT](IMPORTANT): CBIT.stopDepth=295 meter;

2025-01-31T05:16:23.791Z,1738300583.791 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2025-01-31T05:16:23.791Z,1738300583.791 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2025-01-31T05:16:23.791Z,1738300583.791 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2025-01-31T05:16:23.792Z,1738300583.792 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=5 minute;

2025-01-31T05:16:23.792Z,1738300583.792 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2025-01-31T05:16:23.792Z,1738300583.792 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;

2025-01-31T05:16:23.792Z,1738300583.792 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 0.100000 count_per_second;

2025-01-31T05:16:23.792Z,1738300583.792 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 25.000000 count_per_second;

2025-01-31T05:16:23.792Z,1738300583.792 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_caseHumidity 10.000000 percent;

2025-01-31T05:16:23.792Z,1738300583.792 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_diatoms 30.000000 count_per_milliliter;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_dinoflagellates 30.000000 count_per_milliliter;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): Express linearApproximation _.predict_plankton_data_pct_dinos_sqerr 0.100000 none;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): Normal all _.predict_plankton_data_pct_dinos_sqerr;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): ThrusterHE.bestEffortMode=0 bool;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=265.680234 cubic_centimeter;

2025-01-31T05:16:23.793Z,1738300583.793 [SBIT](IMPORTANT): VerticalControl.massDefault=13.329591 millimeter;

2025-01-31T05:16:23.794Z,1738300583.794 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=1 bool;

2025-01-31T05:16:24.242Z,1738300584.242 [MissionManager](IMPORTANT): Started mission Startup
2025-01-31T05:16:24.242Z,1738300584.242 [Startup] Running Loop=1
2025-01-31T05:16:24.243Z,1738300584.243 [Startup](DEBUG): Aggregate::initialize Startup
2025-01-31T05:16:24.243Z,1738300584.243 [Startup:A.GoToSurface] Running Loop=1
2025-01-31T05:16:24.243Z,1738300584.243 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-31T05:16:24.243Z,1738300584.243 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-01-31T05:16:24.271Z,1738300584.271 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-01-31T05:16:24.271Z,1738300584.271 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-01-31T05:16:24.272Z,1738300584.272 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-01-31T05:16:24.272Z,1738300584.272 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-31T05:16:24.272Z,1738300584.272 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-31T05:16:24.274Z,1738300584.274 [Startup:StartupSatComms] Running Loop=1
2025-01-31T05:16:24.274Z,1738300584.274 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-01-31T05:16:24.274Z,1738300584.274 [Startup:StartupSatComms:A] Running Loop=1
2025-01-31T05:16:24.598Z,1738300584.598 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-01-31T05:16:26.245Z,1738300586.245 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,051628.00,A,3641.86555,N,12203.02477,W,0.603,341.38,310125,,,A*77
2025-01-31T05:16:26.247Z,1738300586.247 [NAL9602](INFO): GPS fix at 20250131T051628: (36.697759, -122.050413)
2025-01-31T05:16:26.259Z,1738300586.259 [Startup:StartupSatComms:A] Stopped
2025-01-31T05:16:26.259Z,1738300586.259 [Startup:StartupSatComms:B] Running Loop=1
2025-01-31T05:16:26.598Z,1738300586.598 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:16:26.649Z,1738300586.649 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-01-31T05:16:42.058Z,1738300602.058 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:16:51.763Z,1738300611.763 [NAL9602](INFO): SBD MO Status=1, MOMSN=21466, MT Status=0, MTMSN=0
2025-01-31T05:16:51.816Z,1738300611.816 [NAL9602](INFO): Sent 81 bytes from file Logs/20250130T214453/Courier0040.lzma
2025-01-31T05:16:51.816Z,1738300611.816 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:16:57.068Z,1738300617.068 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:17:05.147Z,1738300625.147 [NAL9602](INFO): SBD MO Status=1, MOMSN=21467, MT Status=0, MTMSN=0
2025-01-31T05:17:05.196Z,1738300625.196 [NAL9602](INFO): Sent 331 bytes from file Logs/20250131T051404/Courier0000.lzma
2025-01-31T05:17:05.196Z,1738300625.196 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:17:25.794Z,1738300645.794 [NAL9602](INFO): SBD MO Status=2, MOMSN=21468, MT Status=2, MTMSN=0
2025-01-31T05:17:25.794Z,1738300645.794 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:17:26.613Z,1738300646.613 [Startup:StartupSatComms:B](INFO): Timed out from 2025-01-31T05:16:26.3Z
2025-01-31T05:17:26.614Z,1738300646.614 [Startup:StartupSatComms:B] Stopped
2025-01-31T05:17:26.615Z,1738300646.615 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-01-31T05:17:26.615Z,1738300646.615 [Startup:StartupSatComms] Stopped
2025-01-31T05:17:26.615Z,1738300646.615 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-01-31T05:17:26.619Z,1738300646.619 [Startup](INFO): Completed Startup
2025-01-31T05:17:26.619Z,1738300646.619 [MissionManager](INFO): Startup is completed.
2025-01-31T05:17:26.619Z,1738300646.619 [MissionManager](INFO): Uninitializing Mission Startup
2025-01-31T05:17:26.619Z,1738300646.619 [Startup] Stopped
2025-01-31T05:17:26.619Z,1738300646.619 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-01-31T05:17:26.619Z,1738300646.619 [Startup:A.GoToSurface] Stopped
2025-01-31T05:17:26.619Z,1738300646.619 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-31T05:17:27.041Z,1738300647.041 [MissionManager](IMPORTANT): Started mission Default
2025-01-31T05:17:27.041Z,1738300647.041 [Default] Running Loop=1
2025-01-31T05:17:27.041Z,1738300647.041 [Default](DEBUG): Aggregate::initialize Default
2025-01-31T05:17:27.041Z,1738300647.041 [Default:B.GoToSurface] Running Loop=1
2025-01-31T05:17:27.041Z,1738300647.041 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-31T05:17:27.041Z,1738300647.041 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-01-31T05:17:27.042Z,1738300647.042 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-01-31T05:17:27.042Z,1738300647.042 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-01-31T05:17:27.042Z,1738300647.042 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-01-31T05:17:27.042Z,1738300647.042 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-31T05:17:27.043Z,1738300647.043 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-31T05:17:27.043Z,1738300647.043 [Default:A.Wait] Running Loop=1
2025-01-31T05:17:27.043Z,1738300647.043 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-01-31T05:17:40.421Z,1738300660.421 [Default:A.Wait](INFO): Done Waiting.
2025-01-31T05:17:40.421Z,1738300660.421 [Default:A.Wait] Stopped
2025-01-31T05:17:40.421Z,1738300660.421 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01-31T05:17:40.818Z,1738300660.818 [Default:CheckIn] Running Loop=1
2025-01-31T05:17:40.818Z,1738300660.818 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-01-31T05:17:40.818Z,1738300660.818 [Default:CheckIn:Read_GPS] Running Loop=1
2025-01-31T05:17:41.279Z,1738300661.279 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-31T05:17:49.286Z,1738300669.286 [NAL9602](INFO): SBD MO Status=2, MOMSN=21468, MT Status=2, MTMSN=0
2025-01-31T05:17:49.286Z,1738300669.286 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:17:50.498Z,1738300670.498 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,051753.00,A,3641.87551,N,12203.02318,W,0.194,354.09,310125,,,A*7E
2025-01-31T05:17:50.501Z,1738300670.501 [NAL9602](INFO): GPS fix at 20250131T051753: (36.697925, -122.050386)
2025-01-31T05:17:50.513Z,1738300670.513 [Default:CheckIn:Read_GPS] Stopped
2025-01-31T05:17:50.513Z,1738300670.513 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-01-31T05:17:50.933Z,1738300670.933 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-01-31T05:18:20.447Z,1738300700.447 [NAL9602](INFO): SBD MO Status=1, MOMSN=21468, MT Status=0, MTMSN=0
2025-01-31T05:18:20.504Z,1738300700.504 [NAL9602](INFO): Sent 73 bytes from file Logs/20250131T051404/Courier0004.lzma
2025-01-31T05:18:20.504Z,1738300700.504 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:18:35.107Z,1738300715.107 [NAL9602](INFO): SBD MO Status=1, MOMSN=21469, MT Status=0, MTMSN=0
2025-01-31T05:18:35.161Z,1738300715.161 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:18:35.161Z,1738300715.161 [NAL9602](INFO): Packets left to send: 13
2025-01-31T05:18:44.903Z,1738300724.903 [NAL9602](INFO): SBD MO Status=1, MOMSN=21470, MT Status=0, MTMSN=0
2025-01-31T05:18:44.952Z,1738300724.952 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:18:44.952Z,1738300724.952 [NAL9602](INFO): Packets left to send: 12
2025-01-31T05:18:57.942Z,1738300737.942 [NAL9602](INFO): SBD MO Status=1, MOMSN=21471, MT Status=0, MTMSN=0
2025-01-31T05:18:58.000Z,1738300738.000 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:18:58.000Z,1738300738.000 [NAL9602](INFO): Packets left to send: 11
2025-01-31T05:19:16.995Z,1738300756.995 [NAL9602](INFO): SBD MO Status=2, MOMSN=21472, MT Status=2, MTMSN=0
2025-01-31T05:19:16.995Z,1738300756.995 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:19:29.158Z,1738300769.158 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2025-01-31T05:19:35.623Z,1738300775.623 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:19:42.090Z,1738300782.090 [NAL9602](INFO): SBD MO Status=2, MOMSN=21472, MT Status=2, MTMSN=0
2025-01-31T05:19:42.090Z,1738300782.090 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:19:49.360Z,1738300789.360 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:20:04.782Z,1738300804.782 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:20:06.812Z,1738300806.812 [NAL9602](INFO): SBD MO Status=1, MOMSN=21472, MT Status=0, MTMSN=0
2025-01-31T05:20:06.862Z,1738300806.862 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:20:06.862Z,1738300806.862 [NAL9602](INFO): Packets left to send: 10
2025-01-31T05:20:18.607Z,1738300818.607 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:20:19.034Z,1738300819.034 [NAL9602](INFO): SBD MO Status=1, MOMSN=21473, MT Status=0, MTMSN=0
2025-01-31T05:20:19.092Z,1738300819.092 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:20:19.092Z,1738300819.092 [NAL9602](INFO): Packets left to send: 9
2025-01-31T05:20:29.959Z,1738300829.959 [NAL9602](INFO): SBD MO Status=1, MOMSN=21474, MT Status=0, MTMSN=0
2025-01-31T05:20:30.016Z,1738300830.016 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:20:30.016Z,1738300830.016 [NAL9602](INFO): Packets left to send: 8
2025-01-31T05:20:33.631Z,1738300833.631 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:20:40.103Z,1738300840.103 [NAL9602](INFO): SBD MO Status=1, MOMSN=21475, MT Status=0, MTMSN=0
2025-01-31T05:20:40.152Z,1738300840.152 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:20:40.152Z,1738300840.152 [NAL9602](INFO): Packets left to send: 7
2025-01-31T05:20:47.814Z,1738300847.814 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:20:52.666Z,1738300852.666 [NAL9602](INFO): SBD MO Status=1, MOMSN=21476, MT Status=0, MTMSN=0
2025-01-31T05:20:52.724Z,1738300852.724 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:20:52.724Z,1738300852.724 [NAL9602](INFO): Packets left to send: 6
2025-01-31T05:21:01.596Z,1738300861.596 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:21:04.430Z,1738300864.430 [NAL9602](INFO): SBD MO Status=1, MOMSN=21477, MT Status=0, MTMSN=0
2025-01-31T05:21:04.480Z,1738300864.480 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:21:04.480Z,1738300864.480 [NAL9602](INFO): Packets left to send: 5
2025-01-31T05:21:14.695Z,1738300874.695 [NAL9602](INFO): SBD MO Status=1, MOMSN=21478, MT Status=0, MTMSN=0
2025-01-31T05:21:14.745Z,1738300874.745 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:21:14.746Z,1738300874.746 [NAL9602](INFO): Packets left to send: 4
2025-01-31T05:21:15.042Z,1738300875.042 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:21:28.451Z,1738300888.451 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:21:36.538Z,1738300896.538 [NAL9602](INFO): SBD MO Status=1, MOMSN=21479, MT Status=0, MTMSN=0
2025-01-31T05:21:36.588Z,1738300896.588 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:21:36.588Z,1738300896.588 [NAL9602](INFO): Packets left to send: 3
2025-01-31T05:21:41.834Z,1738300901.834 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-01-31T05:21:47.898Z,1738300907.898 [NAL9602](INFO): SBD MO Status=1, MOMSN=21480, MT Status=0, MTMSN=0
2025-01-31T05:21:47.952Z,1738300907.952 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:21:47.952Z,1738300907.952 [NAL9602](INFO): Packets left to send: 2
2025-01-31T05:21:58.062Z,1738300918.062 [NAL9602](INFO): SBD MO Status=1, MOMSN=21481, MT Status=0, MTMSN=0
2025-01-31T05:21:58.116Z,1738300918.116 [NAL9602](INFO): Sent 332 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:21:58.116Z,1738300918.116 [NAL9602](INFO): Packets left to send: 1
2025-01-31T05:22:09.430Z,1738300929.430 [NAL9602](INFO): SBD MO Status=1, MOMSN=21482, MT Status=0, MTMSN=0
2025-01-31T05:22:09.480Z,1738300929.480 [NAL9602](INFO): Sent 223 bytes from file Logs/20250130T214453/Express0041.lzma
2025-01-31T05:22:09.480Z,1738300929.480 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:22:25.687Z,1738300945.687 [NAL9602](INFO): SBD MO Status=2, MOMSN=21483, MT Status=2, MTMSN=0
2025-01-31T05:22:25.687Z,1738300945.687 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:22:26.038Z,1738300946.038 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-01-31T05:22:26.039Z,1738300946.039 [BPC1](INFO): Calculating totals. Valid battery stick count: 45. Valid reserve battery stick count: 5.
2025-01-31T05:22:26.042Z,1738300946.042 [BPC1](INFO): Received data from all battery sticks.
2025-01-31T05:22:37.798Z,1738300957.798 [NAL9602](INFO): SBD MO Status=1, MOMSN=21483, MT Status=0, MTMSN=0
2025-01-31T05:22:37.852Z,1738300957.852 [NAL9602](INFO): Sent 332 bytes from file Logs/20250131T051404/Express0001.lzma
2025-01-31T05:22:37.852Z,1738300957.852 [NAL9602](INFO): Packets left to send: 3
2025-01-31T05:22:47.155Z,1738300967.155 [NAL9602](INFO): SBD MO Status=1, MOMSN=21484, MT Status=0, MTMSN=0
2025-01-31T05:22:47.216Z,1738300967.216 [NAL9602](INFO): Sent 332 bytes from file Logs/20250131T051404/Express0001.lzma
2025-01-31T05:22:47.216Z,1738300967.216 [NAL9602](INFO): Packets left to send: 2
2025-01-31T05:22:55.678Z,1738300975.678 [NAL9602](INFO): SBD MO Status=1, MOMSN=21485, MT Status=0, MTMSN=0
2025-01-31T05:22:55.732Z,1738300975.732 [NAL9602](INFO): Sent 332 bytes from file Logs/20250131T051404/Express0001.lzma
2025-01-31T05:22:55.732Z,1738300975.732 [NAL9602](INFO): Packets left to send: 1
2025-01-31T05:23:05.059Z,1738300985.059 [NAL9602](INFO): SBD MO Status=1, MOMSN=21486, MT Status=0, MTMSN=0
2025-01-31T05:23:05.108Z,1738300985.108 [NAL9602](INFO): Sent 305 bytes from file Logs/20250131T051404/Express0001.lzma
2025-01-31T05:23:05.108Z,1738300985.108 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:23:20.042Z,1738301000.042 [NAL9602](INFO): SBD MO Status=2, MOMSN=21487, MT Status=2, MTMSN=0
2025-01-31T05:23:20.043Z,1738301000.043 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:23:39.874Z,1738301019.874 [NAL9602](INFO): SBD MO Status=1, MOMSN=21487, MT Status=0, MTMSN=0
2025-01-31T05:23:39.924Z,1738301019.924 [NAL9602](INFO): Sent 104 bytes from file Logs/20250131T051404/Express0005.lzma
2025-01-31T05:23:39.924Z,1738301019.924 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:23:52.000Z,1738301032.000 [NAL9602](INFO): SBD MO Status=0, MOMSN=21488, MT Status=0, MTMSN=0
2025-01-31T05:23:52.110Z,1738301032.110 [Default:CheckIn:Read_Iridium] Stopped
2025-01-31T05:23:52.110Z,1738301032.110 [Default:CheckIn:C.Wait] Running Loop=1
2025-01-31T05:23:52.111Z,1738301032.111 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-01-31T05:24:22.697Z,1738301062.697 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-31T05:24:52.588Z,1738301092.588 [Power24vConverter](INFO): Powering down.
2025-01-31T05:28:52.576Z,1738301332.576 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-01-31T05:28:52.576Z,1738301332.576 [Default:CheckIn:C.Wait] Stopped
2025-01-31T05:28:52.577Z,1738301332.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-01-31T05:28:52.577Z,1738301332.577 [Default:CheckIn:D] Running Loop=1
2025-01-31T05:28:52.990Z,1738301332.990 [Default:CheckIn:D] Stopped
2025-01-31T05:28:52.990Z,1738301332.990 [Default:CheckIn:E] Running Loop=1
2025-01-31T05:28:53.388Z,1738301333.388 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  11.432487 min 
2025-01-31T05:28:53.388Z,1738301333.388 [Default:CheckIn:E] Stopped
2025-01-31T05:28:53.388Z,1738301333.388 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-01-31T05:28:53.388Z,1738301333.388 [Default:CheckIn] Stopped
2025-01-31T05:28:53.389Z,1738301333.389 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-01-31T05:28:53.389Z,1738301333.389 [Default:CheckIn](INFO): Running loop #2
2025-01-31T05:28:53.389Z,1738301333.389 [Default:CheckIn] Running Loop=2
2025-01-31T05:28:53.389Z,1738301333.389 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-01-31T05:28:53.389Z,1738301333.389 [Default:CheckIn:Read_GPS] Running Loop=1
2025-01-31T05:28:55.395Z,1738301335.395 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,052859.00,A,3641.95716,N,12203.01301,W,0.583,354.68,310125,,,A*74
2025-01-31T05:28:55.397Z,1738301335.397 [NAL9602](INFO): GPS fix at 20250131T052859: (36.699286, -122.050217)
2025-01-31T05:28:55.409Z,1738301335.409 [Default:CheckIn:Read_GPS] Stopped
2025-01-31T05:28:55.409Z,1738301335.409 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-01-31T05:29:22.918Z,1738301362.918 [NAL9602](INFO): SBD MO Status=2, MOMSN=21489, MT Status=2, MTMSN=0
2025-01-31T05:29:22.918Z,1738301362.918 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-31T05:29:41.541Z,1738301381.541 [NAL9602](INFO): SBD MO Status=1, MOMSN=21489, MT Status=0, MTMSN=0
2025-01-31T05:29:41.596Z,1738301381.596 [NAL9602](INFO): Sent 203 bytes from file Logs/20250131T051404/Courier0007.lzma
2025-01-31T05:29:41.596Z,1738301381.596 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:29:49.741Z,1738301389.741 [NAL9602](INFO): SBD MO Status=1, MOMSN=21490, MT Status=0, MTMSN=0
2025-01-31T05:29:49.792Z,1738301389.792 [NAL9602](INFO): Sent 172 bytes from file Logs/20250131T051404/Express0008.lzma
2025-01-31T05:29:49.792Z,1738301389.792 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:30:00.251Z,1738301400.251 [NAL9602](INFO): SBD MO Status=0, MOMSN=21491, MT Status=0, MTMSN=0
2025-01-31T05:30:00.322Z,1738301400.322 [Default:CheckIn:Read_Iridium] Stopped
2025-01-31T05:30:00.322Z,1738301400.322 [Default:CheckIn:C.Wait] Running Loop=1
2025-01-31T05:30:00.322Z,1738301400.322 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-01-31T05:30:30.949Z,1738301430.949 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-31T05:35:00.835Z,1738301700.835 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-01-31T05:35:00.835Z,1738301700.835 [Default:CheckIn:C.Wait] Stopped
2025-01-31T05:35:00.835Z,1738301700.835 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-01-31T05:35:00.835Z,1738301700.835 [Default:CheckIn:D] Running Loop=1
2025-01-31T05:35:01.236Z,1738301701.236 [Default:CheckIn:D] Stopped
2025-01-31T05:35:01.236Z,1738301701.236 [Default:CheckIn:E] Running Loop=1
2025-01-31T05:35:01.650Z,1738301701.650 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  17.569922 min 
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn:E] Stopped
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn] Stopped
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn](INFO): Running loop #3
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn] Running Loop=3
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-01-31T05:35:01.651Z,1738301701.651 [Default:CheckIn:Read_GPS] Running Loop=1
2025-01-31T05:35:03.649Z,1738301703.649 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,053507.00,A,3642.00680,N,12202.99784,W,0.505,48.53,310125,,,A*43
2025-01-31T05:35:03.652Z,1738301703.652 [NAL9602](INFO): GPS fix at 20250131T053507: (36.700113, -122.049964)
2025-01-31T05:35:03.663Z,1738301703.663 [Default:CheckIn:Read_GPS] Stopped
2025-01-31T05:35:03.663Z,1738301703.663 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-01-31T05:35:19.867Z,1738301719.867 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=21492, MT Status=1, MTMSN=636
2025-01-31T05:35:19.928Z,1738301719.928 [NAL9602](INFO): Sent 73 bytes from file Logs/20250131T051404/Courier0010.lzma
2025-01-31T05:35:19.928Z,1738301719.928 [NAL9602](INFO): Packets left to send: 0
2025-01-31T05:35:20.413Z,1738301720.413 [NAL9602](INFO): Received command: restart sys
2025-01-31T05:35:20.415Z,1738301720.415 [CommandExec](IMPORTANT): got command restart system
2025-01-31T05:35:22.496Z,1738301722.496 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-01-31T05:35:22.496Z,1738301722.496 [CommandExec](INFO): Uninitializing the command executive.
2025-01-31T05:35:22.496Z,1738301722.496 [CommandExec](INFO): Uninitializing the command scheduler.
2025-01-31T05:35:22.497Z,1738301722.497 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-01-31T05:35:22.500Z,1738301722.500 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2025-01-31T05:35:22.500Z,1738301722.500 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-01-31T05:35:22.500Z,1738301722.500 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-01-31T05:35:22.501Z,1738301722.501 [NavChartDb](INFO): Join timeout helper Thread ID is 968
2025-01-31T05:35:2