2025-05-29T20:32:15.120Z,1748550735.120 [Supervisor](DEBUG): Initializing supervisor.
2025-05-29T20:32:15.124Z,1748550735.124 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-05-29T20:32:15.125Z,1748550735.125 [SyncHandler](INFO): Protected caller Thread ID is 1026
2025-05-29T20:32:15.125Z,1748550735.125 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-05-29T20:32:15.126Z,1748550735.126 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-05-29T20:32:15.126Z,1748550735.126 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1027
2025-05-29T20:32:15.131Z,1748550735.131 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-05-29T20:32:15.151Z,1748550735.151 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-05-29T20:32:15.152Z,1748550735.152 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-05-29T20:32:15.152Z,1748550735.152 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1028
2025-05-29T20:32:15.157Z,1748550735.157 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-05-29T20:32:15.158Z,1748550735.158 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-05-29T20:32:15.158Z,1748550735.158 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1029
2025-05-29T20:32:15.161Z,1748550735.161 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-05-29T20:32:15.161Z,1748550735.161 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-05-29T20:32:15.162Z,1748550735.162 [logger ThreadHandler](INFO): Protected caller Thread ID is 1030
2025-05-29T20:32:15.166Z,1748550735.166 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-05-29T20:32:15.166Z,1748550735.166 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-05-29T20:32:15.168Z,1748550735.168 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-05-29T20:32:15.273Z,1748550735.273 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-05-29T20:32:15.273Z,1748550735.273 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-05-29T20:32:15.596Z,1748550735.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-05-29T20:32:15.597Z,1748550735.597 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-05-29T20:32:15.869Z,1748550735.869 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-05-29T20:32:15.870Z,1748550735.870 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-05-29T20:32:15.986Z,1748550735.986 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-05-29T20:32:15.986Z,1748550735.986 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-05-29T20:32:16.752Z,1748550736.752 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-05-29T20:32:16.753Z,1748550736.753 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-05-29T20:32:17.276Z,1748550737.276 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-05-29T20:32:17.277Z,1748550737.277 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-05-29T20:32:17.834Z,1748550737.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-05-29T20:32:17.835Z,1748550737.835 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-05-29T20:32:18.262Z,1748550738.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-05-29T20:32:18.262Z,1748550738.262 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-05-29T20:32:18.626Z,1748550738.626 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-05-29T20:32:18.627Z,1748550738.627 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-05-29T20:32:19.018Z,1748550739.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-05-29T20:32:19.018Z,1748550739.018 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-05-29T20:32:19.253Z,1748550739.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-05-29T20:32:19.254Z,1748550739.254 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-05-29T20:32:19.406Z,1748550739.406 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-05-29T20:32:19.407Z,1748550739.407 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-05-29T20:32:19.509Z,1748550739.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-05-29T20:32:19.510Z,1748550739.510 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-05-29T20:32:19.599Z,1748550739.599 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-05-29T20:32:19.795Z,1748550739.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-05-29T20:32:19.796Z,1748550739.796 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-05-29T20:32:20.053Z,1748550740.053 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-05-29T20:32:20.055Z,1748550740.055 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-05-29T20:32:20.056Z,1748550740.056 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-05-29T20:32:20.149Z,1748550740.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-05-29T20:32:20.427Z,1748550740.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-05-29T20:32:20.428Z,1748550740.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-05-29T20:32:20.523Z,1748550740.523 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-05-29T20:32:20.741Z,1748550740.741 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-05-29T20:32:21.011Z,1748550741.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-05-29T20:32:21.160Z,1748550741.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-05-29T20:32:21.417Z,1748550741.417 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-05-29T20:32:21.780Z,1748550741.780 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-05-29T20:32:21.953Z,1748550741.953 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-05-29T20:32:22.060Z,1748550742.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-05-29T20:32:22.155Z,1748550742.155 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-05-29T20:32:22.263Z,1748550742.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-05-29T20:32:22.361Z,1748550742.361 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2025-05-29T20:32:22.361Z,1748550742.361 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-05-29T20:32:22.373Z,1748550742.373 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-05-29T20:32:22.565Z,1748550742.565 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-05-29T20:32:22.565Z,1748550742.565 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-05-29T20:32:22.738Z,1748550742.738 [BuoyancyServo] Loaded
2025-05-29T20:32:22.738Z,1748550742.738 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-05-29T20:32:22.762Z,1748550742.762 [ElevatorServo] Loaded
2025-05-29T20:32:22.762Z,1748550742.762 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-05-29T20:32:22.785Z,1748550742.785 [MassServo] Loaded
2025-05-29T20:32:22.785Z,1748550742.785 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-05-29T20:32:22.807Z,1748550742.807 [RudderServo] Loaded
2025-05-29T20:32:22.808Z,1748550742.808 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-05-29T20:32:22.826Z,1748550742.826 [ThrusterHE] Loaded
2025-05-29T20:32:22.826Z,1748550742.826 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-05-29T20:32:22.827Z,1748550742.827 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-05-29T20:32:22.827Z,1748550742.827 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-05-29T20:32:23.002Z,1748550743.002 [SBIT](DEBUG): Construct Startup Built In Test.
2025-05-29T20:32:23.017Z,1748550743.017 [SBIT] Loaded
2025-05-29T20:32:23.017Z,1748550743.017 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-05-29T20:32:23.020Z,1748550743.020 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-05-29T20:32:23.042Z,1748550743.042 [IBIT] Loaded
2025-05-29T20:32:23.042Z,1748550743.042 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-05-29T20:32:23.047Z,1748550743.047 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-05-29T20:32:23.243Z,1748550743.243 [CBIT] Loaded
2025-05-29T20:32:23.243Z,1748550743.243 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-05-29T20:32:23.275Z,1748550743.275 [GFScanner] Loaded
2025-05-29T20:32:23.275Z,1748550743.275 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-05-29T20:32:23.276Z,1748550743.276 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-05-29T20:32:23.276Z,1748550743.276 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-05-29T20:32:23.454Z,1748550743.454 [CTD_Seabird] Loaded
2025-05-29T20:32:23.454Z,1748550743.454 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-05-29T20:32:23.455Z,1748550743.455 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406864E0
2025-05-29T20:32:23.456Z,1748550743.456 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1118
2025-05-29T20:32:23.491Z,1748550743.491 [ESPComponent] Loaded
2025-05-29T20:32:23.491Z,1748550743.491 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-05-29T20:32:23.513Z,1748550743.513 [PAR_Licor] Loaded
2025-05-29T20:32:23.514Z,1748550743.514 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-05-29T20:32:23.559Z,1748550743.559 [WetLabsBB2FL] Loaded
2025-05-29T20:32:23.560Z,1748550743.560 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-05-29T20:32:23.561Z,1748550743.561 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0
2025-05-29T20:32:23.561Z,1748550743.561 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1119
2025-05-29T20:32:23.562Z,1748550743.562 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-05-29T20:32:23.562Z,1748550743.562 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-05-29T20:32:23.616Z,1748550743.616 [DepthRateCalculator] Loaded
2025-05-29T20:32:23.616Z,1748550743.616 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-05-29T20:32:23.622Z,1748550743.622 [PitchRateCalculator] Loaded
2025-05-29T20:32:23.622Z,1748550743.622 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-05-29T20:32:23.633Z,1748550743.633 [SpeedCalculator] Loaded
2025-05-29T20:32:23.633Z,1748550743.633 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-05-29T20:32:23.638Z,1748550743.638 [YawRateCalculator] Loaded
2025-05-29T20:32:23.638Z,1748550743.638 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-05-29T20:32:23.658Z,1748550743.658 [ElevatorOffsetCalculator] Loaded
2025-05-29T20:32:23.658Z,1748550743.658 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-05-29T20:32:23.659Z,1748550743.659 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-05-29T20:32:23.659Z,1748550743.659 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-05-29T20:32:23.806Z,1748550743.806 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-05-29T20:32:23.806Z,1748550743.806 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-05-29T20:32:23.837Z,1748550743.837 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-05-29T20:32:23.837Z,1748550743.837 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-05-29T20:32:23.955Z,1748550743.955 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-05-29T20:32:23.956Z,1748550743.956 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-05-29T20:32:23.970Z,1748550743.970 [NavChart] Loaded
2025-05-29T20:32:23.970Z,1748550743.970 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-05-29T20:32:23.976Z,1748550743.976 [UniversalFixResidualReporter] Loaded
2025-05-29T20:32:23.976Z,1748550743.976 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-05-29T20:32:23.977Z,1748550743.977 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-05-29T20:32:23.977Z,1748550743.977 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-05-29T20:32:24.485Z,1748550744.485 [AHRS_M2] Loaded
2025-05-29T20:32:24.485Z,1748550744.485 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-05-29T20:32:24.524Z,1748550744.524 [BackseatComponent] Loaded
2025-05-29T20:32:24.525Z,1748550744.525 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-05-29T20:32:24.526Z,1748550744.526 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A824E0
2025-05-29T20:32:24.526Z,1748550744.526 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1120
2025-05-29T20:32:24.529Z,1748550744.529 [LcmUniversalReporter] Loaded
2025-05-29T20:32:24.529Z,1748550744.529 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-05-29T20:32:25.280Z,1748550745.280 [BPC1] Loaded
2025-05-29T20:32:25.281Z,1748550745.281 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-05-29T20:32:25.383Z,1748550745.383 [DAT] Loaded
2025-05-29T20:32:25.384Z,1748550745.384 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-05-29T20:32:25.385Z,1748550745.385 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB24E0
2025-05-29T20:32:25.385Z,1748550745.385 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1121
2025-05-29T20:32:25.459Z,1748550745.459 [DataOverHttps] Loaded
2025-05-29T20:32:25.459Z,1748550745.459 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-05-29T20:32:25.460Z,1748550745.460 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE24E0
2025-05-29T20:32:25.460Z,1748550745.460 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1122
2025-05-29T20:32:25.484Z,1748550745.484 [Depth_Keller] Loaded
2025-05-29T20:32:25.485Z,1748550745.485 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-05-29T20:32:25.490Z,1748550745.490 [DropWeight] Loaded
2025-05-29T20:32:25.490Z,1748550745.490 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-05-29T20:32:25.554Z,1748550745.554 [NAL9602] Loaded
2025-05-29T20:32:25.554Z,1748550745.554 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-05-29T20:32:25.580Z,1748550745.580 [Onboard] Loaded
2025-05-29T20:32:25.581Z,1748550745.581 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-05-29T20:32:25.582Z,1748550745.582 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B124E0
2025-05-29T20:32:25.582Z,1748550745.582 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1123
2025-05-29T20:32:25.588Z,1748550745.588 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2025-05-29T20:32:25.602Z,1748550745.602 [PowerOnly] Loaded
2025-05-29T20:32:25.603Z,1748550745.603 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-05-29T20:32:25.617Z,1748550745.617 [Power24vConverter] Loaded
2025-05-29T20:32:25.617Z,1748550745.617 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-05-29T20:32:25.633Z,1748550745.633 [Radio_Surface] Loaded
2025-05-29T20:32:25.634Z,1748550745.634 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-05-29T20:32:25.635Z,1748550745.635 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B424E0
2025-05-29T20:32:25.635Z,1748550745.635 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1124
2025-05-29T20:32:25.651Z,1748550745.651 [Sonardyne_Nano] Loaded
2025-05-29T20:32:25.652Z,1748550745.652 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-05-29T20:32:25.652Z,1748550745.652 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-05-29T20:32:25.653Z,1748550745.653 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-05-29T20:32:25.716Z,1748550745.716 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-05-29T20:32:25.716Z,1748550745.716 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-05-29T20:32:25.962Z,1748550745.962 [VerticalControl](DEBUG): Construct VerticalControl.
2025-05-29T20:32:26.066Z,1748550746.066 [VerticalControl] Loaded
2025-05-29T20:32:26.067Z,1748550746.067 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-05-29T20:32:26.070Z,1748550746.070 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-05-29T20:32:26.115Z,1748550746.115 [HorizontalControl] Loaded
2025-05-29T20:32:26.116Z,1748550746.116 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-05-29T20:32:26.121Z,1748550746.121 [SpeedControl](DEBUG): Construct SpeedControl.
2025-05-29T20:32:26.124Z,1748550746.124 [SpeedControl] Loaded
2025-05-29T20:32:26.124Z,1748550746.124 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-05-29T20:32:26.127Z,1748550746.127 [LoopControl](DEBUG): Construct LoopControl.
2025-05-29T20:32:26.127Z,1748550746.127 [LoopControl] Loaded
2025-05-29T20:32:26.128Z,1748550746.128 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-05-29T20:32:26.128Z,1748550746.128 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-05-29T20:32:26.129Z,1748550746.129 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-05-29T20:32:26.139Z,1748550746.139 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-05-29T20:32:26.140Z,1748550746.140 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-05-29T20:32:26.517Z,1748550746.517 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-05-29T20:32:26.524Z,1748550746.524 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-05-29T20:32:26.527Z,1748550746.527 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-05-29T20:32:26.538Z,1748550746.538 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-05-29T20:32:26.539Z,1748550746.539 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C684E0
2025-05-29T20:32:26.540Z,1748550746.540 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1125
2025-05-29T20:32:26.544Z,1748550746.544 [Supervisor](INFO): Main Thread ID is 824
2025-05-29T20:32:26.544Z,1748550746.544 [Supervisor](DEBUG): Running supervisor.
2025-05-29T20:32:26.545Z,1748550746.545 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1126
2025-05-29T20:32:26.545Z,1748550746.545 [CommandExec](INFO): Initializing the command executive.
2025-05-29T20:32:26.547Z,1748550746.547 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1127
2025-05-29T20:32:26.550Z,1748550746.550 [controlThread ThreadHandler](INFO): Handler Thread ID is 1128
2025-05-29T20:32:26.551Z,1748550746.551 [controlThread](DEBUG): Initializing ControlThread
2025-05-29T20:32:26.553Z,1748550746.553 [SBIT](INFO): Initialize SBIT Component.
2025-05-29T20:32:26.553Z,1748550746.553 [SBIT](IMPORTANT): git: 2025-05-29
2025-05-29T20:32:26.553Z,1748550746.553 [SBIT](INFO): git hash: c78c975c7bb2a66b27244d2837f68dff299fa024
2025-05-29T20:32:26.553Z,1748550746.553 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-05-29T20:32:26.555Z,1748550746.555 [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-05-29T20:32:26.556Z,1748550746.556 [SBIT](INFO): Beginning SBIT in 125.000000 seconds.
2025-05-29T20:32:26.557Z,1748550746.557 [IBIT](INFO): Initialize IBIT Component.
2025-05-29T20:32:26.557Z,1748550746.557 [CBIT](DEBUG): Initialize CBIT Component.
2025-05-29T20:32:26.558Z,1748550746.558 [logger ThreadHandler](INFO): Handler Thread ID is 1129
2025-05-29T20:32:26.572Z,1748550746.572 [CBIT](DEBUG): Initialized mux pins.
2025-05-29T20:32:26.572Z,1748550746.572 [CBIT](DEBUG): Initializing the watchdog timer.
2025-05-29T20:32:26.584Z,1748550746.584 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1130
2025-05-29T20:32:26.585Z,1748550746.585 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-05-29T20:32:26.589Z,1748550746.589 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1132
2025-05-29T20:32:26.592Z,1748550746.592 [WetLabsBB2FL](INFO): Powering up
2025-05-29T20:32:26.594Z,1748550746.594 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1134
2025-05-29T20:32:26.596Z,1748550746.596 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-05-29T20:32:26.596Z,1748550746.596 [CBIT](DEBUG): Initializing heartbeat.
2025-05-29T20:32:26.610Z,1748550746.610 [DAT ThreadHandler](INFO): Handler Thread ID is 1135
2025-05-29T20:32:26.611Z,1748550746.611 [DAT](INFO): Powering up
2025-05-29T20:32:26.611Z,1748550746.611 [DAT](DEBUG): Initializing DAT.
2025-05-29T20:32:26.617Z,1748550746.617 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1137
2025-05-29T20:32:26.619Z,1748550746.619 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-05-29T20:32:26.632Z,1748550746.632 [Onboard ThreadHandler](INFO): Handler Thread ID is 1138
2025-05-29T20:32:26.650Z,1748550746.650 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1139
2025-05-29T20:32:26.668Z,1748550746.668 [CBIT](DEBUG): Deactivating emergency mode.
2025-05-29T20:32:26.669Z,1748550746.669 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1140
2025-05-29T20:32:26.671Z,1748550746.671 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-05-29T20:32:26.671Z,1748550746.671 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-05-29T20:32:26.671Z,1748550746.671 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-05-29T20:32:26.671Z,1748550746.671 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-05-29T20:32:26.672Z,1748550746.672 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-05-29T20:32:26.672Z,1748550746.672 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-05-29T20:32:26.672Z,1748550746.672 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-05-29T20:32:26.672Z,1748550746.672 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-05-29T20:32:26.708Z,1748550746.708 [CBIT](DEBUG): Backplane powered.
2025-05-29T20:32:26.708Z,1748550746.708 [GFScanner](DEBUG): Initializing GFScanner
2025-05-29T20:32:26.708Z,1748550746.708 [GFScanner](DEBUG): Deactivating GF circuits.
2025-05-29T20:32:26.716Z,1748550746.716 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-05-29T20:32:26.717Z,1748550746.717 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-05-29T20:32:26.717Z,1748550746.717 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-05-29T20:32:26.717Z,1748550746.717 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-05-29T20:32:26.718Z,1748550746.718 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-05-29T20:32:26.719Z,1748550746.719 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-05-29T20:32:26.719Z,1748550746.719 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-05-29T20:32:26.723Z,1748550746.723 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-05-29T20:32:26.728Z,1748550746.728 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-05-29T20:32:26.729Z,1748550746.729 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-05-29T20:32:26.730Z,1748550746.730 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-05-29T20:32:26.730Z,1748550746.730 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-05-29T20:32:26.731Z,1748550746.731 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-05-29T20:32:26.731Z,1748550746.731 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-05-29T20:32:26.741Z,1748550746.741 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-05-29T20:32:26.829Z,1748550746.829 [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-05-29T20:32:26.833Z,1748550746.833 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-29T20:32:26.888Z,1748550746.888 [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-05-29T20:32:26.889Z,1748550746.889 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-05-29T20:32:26.889Z,1748550746.889 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-05-29T20:32:26.890Z,1748550746.890 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-05-29T20:32:27.056Z,1748550747.056 [Radio_Surface](INFO): Powering up
2025-05-29T20:32:27.217Z,1748550747.217 [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-05-29T20:32:27.239Z,1748550747.239 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-05-29T20:32:27.241Z,1748550747.241 [Default:A.Wait](DEBUG): Construct Wait.
2025-05-29T20:32:27.243Z,1748550747.243 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-29T20:32:27.292Z,1748550747.292 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-05-29T20:32:27.295Z,1748550747.295 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-05-29T20:32:27.317Z,1748550747.317 [Default:E.Execute](DEBUG): Construct Execute.
2025-05-29T20:32:27.320Z,1748550747.320 [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-05-29T20:32:27.340Z,1748550747.340 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,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,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-05-29T20:32:27.350Z,1748550747.350 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-05-29T20:32:27.409Z,1748550747.409 [Depth_Keller](INFO): Initializing.
2025-05-29T20:32:27.411Z,1748550747.411 [PowerOnly](INFO): Powering up loadControl
2025-05-29T20:32:27.428Z,1748550747.428 [Power24vConverter](INFO): Powering up.
2025-05-29T20:32:27.429Z,1748550747.429 [Sonardyne_Nano](INFO): Initializing.
2025-05-29T20:32:27.456Z,1748550747.456 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-05-29T20:32:27.479Z,1748550747.479 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-05-29T20:32:27.484Z,1748550747.484 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-05-29T20:32:27.485Z,1748550747.485 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-05-29T20:32:27.492Z,1748550747.492 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-05-29T20:32:27.493Z,1748550747.493 [MassServo](DEBUG): Initializing EZServoServo.
2025-05-29T20:32:27.500Z,1748550747.500 [MassServo](DEBUG): Initializing MassServo.
2025-05-29T20:32:27.501Z,1748550747.501 [RudderServo](DEBUG): Initializing EZServoServo.
2025-05-29T20:32:27.508Z,1748550747.508 [RudderServo](DEBUG): Initializing RudderServo.
2025-05-29T20:32:27.509Z,1748550747.509 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-05-29T20:32:27.516Z,1748550747.516 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-05-29T20:32:29.204Z,1748550749.204 [WetLabsBB2FL](INFO): Powering down
2025-05-29T20:32:29.375Z,1748550749.375 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-05-29T20:32:30.661Z,1748550750.661 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-05-29T20:32:33.616Z,1748550753.616 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-05-29T20:32:38.708Z,1748550758.708 [DAT](INFO): DAT read: 

2025-05-29T20:32:38.710Z,1748550758.710 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2025-05-29T20:32:40.473Z,1748550760.473 [DAT](INFO): DAT read: MF Frequency Band

2025-05-29T20:32:40.474Z,1748550760.474 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2025-05-29T20:32:40.475Z,1748550760.475 [DAT](INFO): DAT read: May 29 2025 20:32:34 

2025-05-29T20:32:41.733Z,1748550761.733 [DAT](INFO): DAT read: Features enabled [Bearing]

2025-05-29T20:32:41.734Z,1748550761.734 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2025-05-29T20:32:41.734Z,1748550761.734 [DAT](INFO): commRate: 1200
2025-05-29T20:32:43.800Z,1748550763.800 [DAT](INFO): entering command mode
2025-05-29T20:32:44.001Z,1748550764.001 [DAT](INFO): DAT read: 

2025-05-29T20:32:44.001Z,1748550764.001 [DAT](INFO): DAT read: user:1>

2025-05-29T20:32:44.001Z,1748550764.001 [DAT](INFO): setting verbose to 3
2025-05-29T20:32:44.253Z,1748550764.253 [DAT](INFO): DAT read: user:1>

2025-05-29T20:32:44.254Z,1748550764.254 [DAT](INFO): DAT read: Verbose         | 3           

2025-05-29T20:32:44.254Z,1748550764.254 [DAT](INFO): set verbose to 3
2025-05-29T20:32:44.254Z,1748550764.254 [DAT](INFO): setting DatVerbose to 27440
2025-05-29T20:32:44.505Z,1748550764.505 [DAT](INFO): DAT read: user:2>

2025-05-29T20:32:44.506Z,1748550764.506 [DAT](INFO): DAT read: DatVerbose      | 27440       

2025-05-29T20:32:44.506Z,1748550764.506 [DAT](INFO): set DatVerbose to 27440
2025-05-29T20:32:44.506Z,1748550764.506 [DAT](INFO): setting transmit power to 8
2025-05-29T20:32:44.757Z,1748550764.757 [DAT](INFO): DAT read: user:3>

2025-05-29T20:32:44.758Z,1748550764.758 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2025-05-29T20:32:44.758Z,1748550764.758 [DAT](INFO): set transmit power to 8
2025-05-29T20:32:44.758Z,1748550764.758 [DAT](INFO): setting local address to 5
2025-05-29T20:32:45.009Z,1748550765.009 [DAT](INFO): DAT read: user:4>

2025-05-29T20:32:45.010Z,1748550765.010 [DAT](INFO): DAT read: LocalAddr       | 5           

2025-05-29T20:32:45.010Z,1748550765.010 [DAT](INFO): set local address to 5
2025-05-29T20:32:45.011Z,1748550765.011 [DAT](INFO): Setting time to: 20:32:45 And date to:5/29/2025
2025-05-29T20:32:45.261Z,1748550765.261 [DAT](INFO): DAT read: user:5>

2025-05-29T20:32:45.262Z,1748550765.262 [DAT](INFO): DAT read: Thu May 29, 2025  20:32:45  

2025-05-29T20:32:45.262Z,1748550765.262 [DAT](INFO): Local DAT time set to Thu May 29, 2025  20:32:45  

2025-05-29T20:32:55.642Z,1748550775.642 [NAL9602](INFO): Powering up NAL9602
2025-05-29T20:33:06.547Z,1748550786.547 [NAL9602](INFO): NAL9602 initialized
2025-05-29T20:34:32.285Z,1748550872.285 [SBIT](IMPORTANT): Beginning Startup BIT
2025-05-29T20:34:32.289Z,1748550872.289 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-29T20:34:36.813Z,1748550876.813 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002570
CHAN A1 (24V): 0.002654
CHAN A2 (12V): -0.006059
CHAN A3 (5V): -0.011842
CHAN B0 (3.3V): -0.003480
CHAN B1 (3.15aV): -0.001909
CHAN B2 (3.15bV): -0.001138
CHAN B3 (GND): -0.003202
OPEN: 0.011921
Full Scale: +/- 1 mA
2025-05-29T20:34:39.027Z,1748550879.027 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004415
2025-05-29T20:35:26.330Z,1748550926.330 [SBIT](IMPORTANT): SBIT PASSED
2025-05-29T20:35:26.330Z,1748550926.330 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-05-29T20:35:26.331Z,1748550926.331 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;

2025-05-29T20:35:26.331Z,1748550926.331 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool;

2025-05-29T20:35:26.331Z,1748550926.331 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2025-05-29T20:35:26.331Z,1748550926.331 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2025-05-29T20:35:26.331Z,1748550926.331 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=5 minute;

2025-05-29T20:35:26.331Z,1748550926.331 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2025-05-29T20:35:26.336Z,1748550926.336 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2025-05-29T20:35:26.336Z,1748550926.336 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;

2025-05-29T20:35:26.336Z,1748550926.336 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;

2025-05-29T20:35:26.336Z,1748550926.336 [SBIT](IMPORTANT): ThrusterHE.bestEffortMode=0 bool;

2025-05-29T20:35:26.336Z,1748550926.336 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=266.500578 cubic_centimeter;

2025-05-29T20:35:26.336Z,1748550926.336 [SBIT](IMPORTANT): VerticalControl.massDefault=26.489817 millimeter;

2025-05-29T20:35:26.701Z,1748550926.701 [MissionManager](IMPORTANT): Started mission Startup
2025-05-29T20:35:26.702Z,1748550926.702 [Startup] Running Loop=1
2025-05-29T20:35:26.702Z,1748550926.702 [Startup](DEBUG): Aggregate::initialize Startup
2025-05-29T20:35:26.702Z,1748550926.702 [Startup:A.GoToSurface] Running Loop=1
2025-05-29T20:35:26.702Z,1748550926.702 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-29T20:35:26.702Z,1748550926.702 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-29T20:35:26.703Z,1748550926.703 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-29T20:35:26.703Z,1748550926.703 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-29T20:35:26.704Z,1748550926.704 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-29T20:35:26.704Z,1748550926.704 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-29T20:35:26.704Z,1748550926.704 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-29T20:35:26.706Z,1748550926.706 [Startup:StartupSatComms] Running Loop=1
2025-05-29T20:35:26.706Z,1748550926.706 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-05-29T20:35:26.706Z,1748550926.706 [Startup:StartupSatComms:A] Running Loop=1
2025-05-29T20:35:27.108Z,1748550927.108 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-05-29T20:35:27.108Z,1748550927.108 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-29T20:35:27.110Z,1748550927.110 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-05-29T20:35:27.122Z,1748550927.122 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-29T20:35:27.574Z,1748550927.574 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-29T20:35:27.574Z,1748550927.574 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-05-29T20:36:26.898Z,1748550986.898 [Startup:StartupSatComms:A](INFO): Timed out from 2025-05-29T20:35:26.7Z
2025-05-29T20:36:26.898Z,1748550986.898 [Startup:StartupSatComms:A] Stopped
2025-05-29T20:36:26.898Z,1748550986.898 [Startup:StartupSatComms:B] Running Loop=1
2025-05-29T20:36:27.291Z,1748550987.291 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-29T20:37:27.133Z,1748551047.133 [Startup:StartupSatComms:B](INFO): Timed out from 2025-05-29T20:36:26.9Z
2025-05-29T20:37:27.133Z,1748551047.133 [Startup:StartupSatComms:B] Stopped
2025-05-29T20:37:27.133Z,1748551047.133 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-05-29T20:37:27.133Z,1748551047.133 [Startup:StartupSatComms] Stopped
2025-05-29T20:37:27.133Z,1748551047.133 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-05-29T20:37:27.134Z,1748551047.134 [Startup](INFO): Completed Startup
2025-05-29T20:37:27.134Z,1748551047.134 [MissionManager](INFO): Startup is completed.
2025-05-29T20:37:27.135Z,1748551047.135 [MissionManager](INFO): Uninitializing Mission Startup
2025-05-29T20:37:27.135Z,1748551047.135 [Startup] Stopped
2025-05-29T20:37:27.135Z,1748551047.135 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-05-29T20:37:27.135Z,1748551047.135 [Startup:A.GoToSurface] Stopped
2025-05-29T20:37:27.135Z,1748551047.135 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-05-29T20:37:27.709Z,1748551047.709 [MissionManager](IMPORTANT): Started mission Default
2025-05-29T20:37:27.710Z,1748551047.710 [Default] Running Loop=1
2025-05-29T20:37:27.710Z,1748551047.710 [Default](DEBUG): Aggregate::initialize Default
2025-05-29T20:37:27.710Z,1748551047.710 [Default:B.GoToSurface] Running Loop=1
2025-05-29T20:37:27.710Z,1748551047.710 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-29T20:37:27.710Z,1748551047.710 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-29T20:37:27.710Z,1748551047.710 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-29T20:37:27.711Z,1748551047.711 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-29T20:37:27.711Z,1748551047.711 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-29T20:37:27.711Z,1748551047.711 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-29T20:37:27.720Z,1748551047.720 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-29T20:37:27.720Z,1748551047.720 [Default:A.Wait] Running Loop=1
2025-05-29T20:37:27.720Z,1748551047.720 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-05-29T20:37:41.026Z,1748551061.026 [Default:A.Wait](INFO): Done Waiting.
2025-05-29T20:37:41.026Z,1748551061.026 [Default:A.Wait] Stopped
2025-05-29T20:37:41.026Z,1748551061.026 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T20:37:41.409Z,1748551061.409 [Default:CheckIn] Running Loop=1
2025-05-29T20:37:41.409Z,1748551061.409 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T20:37:41.409Z,1748551061.409 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T20:37:41.742Z,1748551061.742 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-05-29T20:38:09.558Z,1748551089.558 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T20:38:13.591Z,1748551093.591 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203800.00,A,3648.16144,N,12147.28429,W,0.214,0.00,290525,,,D*75
2025-05-29T20:38:13.595Z,1748551093.595 [NAL9602](INFO): GPS fix at 20250529T203800: (36.802691, -121.788072)
2025-05-29T20:38:13.606Z,1748551093.606 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T20:38:13.606Z,1748551093.606 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T20:38:14.017Z,1748551094.017 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-29T20:38:45.965Z,1748551125.965 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T20:39:33.435Z,1748551173.435 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250529T181614/Courier0070.lzma
2025-05-29T20:39:34.438Z,1748551174.438 [DataOverHttps](INFO): Moved sent file to Logs/20250529T181614/Courier0070.lzma.bak
2025-05-29T20:39:34.438Z,1748551174.438 [DataOverHttps](INFO): SBD MOMSN=25034081
2025-05-29T20:39:51.640Z,1748551191.640 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250529T202502/Courier0000.lzma
2025-05-29T20:39:52.642Z,1748551192.642 [DataOverHttps](INFO): Moved sent file to Logs/20250529T202502/Courier0000.lzma.bak
2025-05-29T20:39:52.642Z,1748551192.642 [DataOverHttps](INFO): SBD MOMSN=25034091
2025-05-29T20:40:08.788Z,1748551208.788 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20250529T202502/Courier0004.lzma
2025-05-29T20:40:09.790Z,1748551209.790 [DataOverHttps](INFO): Moved sent file to Logs/20250529T202502/Courier0004.lzma.bak
2025-05-29T20:40:09.790Z,1748551209.790 [DataOverHttps](INFO): SBD MOMSN=25034105
2025-05-29T20:40:27.767Z,1748551227.767 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250529T202502/Courier0007.lzma
2025-05-29T20:40:28.770Z,1748551228.770 [DataOverHttps](INFO): Moved sent file to Logs/20250529T202502/Courier0007.lzma.bak
2025-05-29T20:40:28.770Z,1748551228.770 [DataOverHttps](INFO): SBD MOMSN=25034151
2025-05-29T20:40:44.780Z,1748551244.780 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250529T203215/Courier0000.lzma
2025-05-29T20:40:45.782Z,1748551245.782 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0000.lzma.bak
2025-05-29T20:40:45.782Z,1748551245.782 [DataOverHttps](INFO): SBD MOMSN=25034153
2025-05-29T20:41:01.744Z,1748551261.744 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20250529T203215/Courier0004.lzma
2025-05-29T20:41:02.189Z,1748551262.189 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-29T20:41:02.190Z,1748551262.190 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-05-29T20:41:02.191Z,1748551262.191 [BPC1](ERROR): Battery stick #53 (s/n: 0459) reported OVER_TEMP_ALARM. Status code: 0x1717.
2025-05-29T20:41:02.191Z,1748551262.191 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 6.
2025-05-29T20:41:02.195Z,1748551262.195 [BPC1](INFO): Received data from all battery sticks.
2025-05-29T20:41:02.746Z,1748551262.746 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0004.lzma.bak
2025-05-29T20:41:02.746Z,1748551262.746 [DataOverHttps](INFO): SBD MOMSN=25034156
2025-05-29T20:41:18.691Z,1748551278.691 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250529T181614/Express0071.lzma
2025-05-29T20:41:19.694Z,1748551279.694 [DataOverHttps](INFO): Moved sent file to Logs/20250529T181614/Express0071.lzma.bak
2025-05-29T20:41:19.694Z,1748551279.694 [DataOverHttps](INFO): SBD MOMSN=25034159
2025-05-29T20:41:35.686Z,1748551295.686 [DataOverHttps](INFO): Sending 989 bytes from file Logs/20250529T202502/Express0001.lzma
2025-05-29T20:41:36.686Z,1748551296.686 [DataOverHttps](INFO): Moved sent file to Logs/20250529T202502/Express0001.lzma.bak
2025-05-29T20:41:36.686Z,1748551296.686 [DataOverHttps](INFO): SBD MOMSN=25034161
2025-05-29T20:41:52.573Z,1748551312.573 [DataOverHttps](INFO): Sending 355 bytes from file Logs/20250529T202502/Express0005.lzma
2025-05-29T20:41:53.574Z,1748551313.574 [DataOverHttps](INFO): Moved sent file to Logs/20250529T202502/Express0005.lzma.bak
2025-05-29T20:41:53.574Z,1748551313.574 [DataOverHttps](INFO): SBD MOMSN=25034186
2025-05-29T20:42:09.641Z,1748551329.641 [DataOverHttps](INFO): Sending 576 bytes from file Logs/20250529T202502/Express0008.lzma
2025-05-29T20:42:10.642Z,1748551330.642 [DataOverHttps](INFO): Moved sent file to Logs/20250529T202502/Express0008.lzma.bak
2025-05-29T20:42:10.642Z,1748551330.642 [DataOverHttps](INFO): SBD MOMSN=25034190
2025-05-29T20:42:26.570Z,1748551346.570 [DataOverHttps](INFO): Sending 957 bytes from file Logs/20250529T203215/Express0001.lzma
2025-05-29T20:42:27.570Z,1748551347.570 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0001.lzma.bak
2025-05-29T20:42:27.570Z,1748551347.570 [DataOverHttps](INFO): SBD MOMSN=25034209
2025-05-29T20:42:43.628Z,1748551363.628 [DataOverHttps](INFO): Sending 399 bytes from file Logs/20250529T203215/Express0005.lzma
2025-05-29T20:42:44.939Z,1748551364.939 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0005.lzma.bak
2025-05-29T20:42:44.939Z,1748551364.939 [DataOverHttps](INFO): SBD MOMSN=25034236
2025-05-29T20:42:46.366Z,1748551366.366 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T20:42:46.366Z,1748551366.366 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T20:42:46.366Z,1748551366.366 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T20:47:46.934Z,1748551666.934 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T20:47:46.935Z,1748551666.935 [Default:CheckIn:C.Wait] Stopped
2025-05-29T20:47:46.935Z,1748551666.935 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T20:47:46.935Z,1748551666.935 [Default:CheckIn:D] Running Loop=1
2025-05-29T20:47:47.336Z,1748551667.336 [Default:CheckIn:D] Stopped
2025-05-29T20:47:47.336Z,1748551667.336 [Default:CheckIn:E] Running Loop=1
2025-05-29T20:47:47.756Z,1748551667.756 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  10.327097 min 
2025-05-29T20:47:47.756Z,1748551667.756 [Default:CheckIn:E] Stopped
2025-05-29T20:47:47.757Z,1748551667.757 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T20:47:47.757Z,1748551667.757 [Default:CheckIn] Stopped
2025-05-29T20:47:47.757Z,1748551667.757 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T20:47:47.757Z,1748551667.757 [Default:CheckIn](INFO): Running loop #2
2025-05-29T20:47:47.757Z,1748551667.757 [Default:CheckIn] Running Loop=2
2025-05-29T20:47:47.757Z,1748551667.757 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T20:47:47.758Z,1748551667.758 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T20:47:49.743Z,1748551669.743 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204736.00,A,3648.16252,N,12147.28019,W,0.175,0.00,290525,,,D*7F
2025-05-29T20:47:49.747Z,1748551669.747 [NAL9602](INFO): GPS fix at 20250529T204736: (36.802709, -121.788003)
2025-05-29T20:47:49.758Z,1748551669.758 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T20:47:49.758Z,1748551669.758 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T20:47:56.948Z,1748551676.948 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20250529T203215/Courier0007.lzma
2025-05-29T20:47:57.950Z,1748551677.950 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0007.lzma.bak
2025-05-29T20:47:57.950Z,1748551677.950 [DataOverHttps](INFO): SBD MOMSN=25034255
2025-05-29T20:48:13.912Z,1748551693.912 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20250529T203215/Express0008.lzma
2025-05-29T20:48:14.914Z,1748551694.914 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0008.lzma.bak
2025-05-29T20:48:14.914Z,1748551694.914 [DataOverHttps](INFO): SBD MOMSN=25034258
2025-05-29T20:48:16.421Z,1748551696.421 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T20:48:16.421Z,1748551696.421 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T20:48:16.421Z,1748551696.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T20:48:20.441Z,1748551700.441 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T20:48:20.520Z,1748551700.520 [NAL9602](ERROR): received: 
+CSQ:0

OK
2025-05-29T20:49:14.583Z,1748551754.583 [NAL9602](INFO): SBD MO Status=2, MOMSN=20746, MT Status=2, MTMSN=0
2025-05-29T20:49:14.583Z,1748551754.583 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T20:52:51.932Z,1748551971.932 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T20:53:16.990Z,1748551996.990 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T20:53:16.990Z,1748551996.990 [Default:CheckIn:C.Wait] Stopped
2025-05-29T20:53:16.990Z,1748551996.990 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T20:53:16.990Z,1748551996.990 [Default:CheckIn:D] Running Loop=1
2025-05-29T20:53:17.391Z,1748551997.391 [Default:CheckIn:D] Stopped
2025-05-29T20:53:17.391Z,1748551997.391 [Default:CheckIn:E] Running Loop=1
2025-05-29T20:53:17.799Z,1748551997.799 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  15.828017 min 
2025-05-29T20:53:17.799Z,1748551997.799 [Default:CheckIn:E] Stopped
2025-05-29T20:53:17.800Z,1748551997.800 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T20:53:17.800Z,1748551997.800 [Default:CheckIn] Stopped
2025-05-29T20:53:17.800Z,1748551997.800 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T20:53:17.800Z,1748551997.800 [Default:CheckIn](INFO): Running loop #3
2025-05-29T20:53:17.800Z,1748551997.800 [Default:CheckIn] Running Loop=3
2025-05-29T20:53:17.800Z,1748551997.800 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T20:53:17.800Z,1748551997.800 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T20:53:19.806Z,1748551999.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205306.00,A,3648.16191,N,12147.28069,W,0.272,89.24,290525,,,D*41
2025-05-29T20:53:19.808Z,1748551999.808 [NAL9602](INFO): GPS fix at 20250529T205306: (36.802698, -121.788011)
2025-05-29T20:53:19.848Z,1748551999.848 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T20:53:19.848Z,1748551999.848 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T20:53:27.023Z,1748552007.023 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0010.lzma
2025-05-29T20:53:28.026Z,1748552008.026 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0010.lzma.bak
2025-05-29T20:53:28.026Z,1748552008.026 [DataOverHttps](INFO): SBD MOMSN=25034328
2025-05-29T20:53:44.009Z,1748552024.009 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20250529T203215/Express0011.lzma
2025-05-29T20:53:45.010Z,1748552025.010 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0011.lzma.bak
2025-05-29T20:53:45.010Z,1748552025.010 [DataOverHttps](INFO): SBD MOMSN=25034331
2025-05-29T20:53:46.910Z,1748552026.910 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T20:53:46.910Z,1748552026.910 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T20:53:46.911Z,1748552026.911 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T20:53:52.127Z,1748552032.127 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T20:58:47.465Z,1748552327.465 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T20:58:47.465Z,1748552327.465 [Default:CheckIn:C.Wait] Stopped
2025-05-29T20:58:47.465Z,1748552327.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T20:58:47.465Z,1748552327.465 [Default:CheckIn:D] Running Loop=1
2025-05-29T20:58:47.862Z,1748552327.862 [Default:CheckIn:D] Stopped
2025-05-29T20:58:47.862Z,1748552327.862 [Default:CheckIn:E] Running Loop=1
2025-05-29T20:58:48.271Z,1748552328.271 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  21.335868 min 
2025-05-29T20:58:48.272Z,1748552328.272 [Default:CheckIn:E] Stopped
2025-05-29T20:58:48.272Z,1748552328.272 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T20:58:48.272Z,1748552328.272 [Default:CheckIn] Stopped
2025-05-29T20:58:48.272Z,1748552328.272 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T20:58:48.272Z,1748552328.272 [Default:CheckIn](INFO): Running loop #4
2025-05-29T20:58:48.272Z,1748552328.272 [Default:CheckIn] Running Loop=4
2025-05-29T20:58:48.272Z,1748552328.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T20:58:48.273Z,1748552328.273 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T20:58:50.279Z,1748552330.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205836.00,A,3648.15968,N,12147.28357,W,0.194,10.88,290525,,,D*47
2025-05-29T20:58:50.282Z,1748552330.282 [NAL9602](INFO): GPS fix at 20250529T205836: (36.802661, -121.788060)
2025-05-29T20:58:50.293Z,1748552330.293 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T20:58:50.293Z,1748552330.293 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T20:58:57.647Z,1748552337.647 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250529T203215/Courier0013.lzma
2025-05-29T20:58:58.650Z,1748552338.650 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0013.lzma.bak
2025-05-29T20:58:58.650Z,1748552338.650 [DataOverHttps](INFO): SBD MOMSN=25034348
2025-05-29T20:59:14.520Z,1748552354.520 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250529T203215/Express0014.lzma
2025-05-29T20:59:15.522Z,1748552355.522 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0014.lzma.bak
2025-05-29T20:59:15.522Z,1748552355.522 [DataOverHttps](INFO): SBD MOMSN=25034351
2025-05-29T20:59:16.960Z,1748552356.960 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T20:59:16.960Z,1748552356.960 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T20:59:16.960Z,1748552356.960 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T20:59:20.981Z,1748552360.981 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T20:59:21.060Z,1748552361.060 [NAL9602](ERROR): received: 
+CSQ:0

OK746, 2, 0, 0, 0

OK
2025-05-29T21:03:52.920Z,1748552632.920 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T21:04:17.578Z,1748552657.578 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:04:17.578Z,1748552657.578 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:04:17.578Z,1748552657.578 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:04:17.578Z,1748552657.579 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:04:17.978Z,1748552657.978 [Default:CheckIn:D] Stopped
2025-05-29T21:04:17.978Z,1748552657.978 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  26.837799 min 
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn:E] Stopped
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn] Stopped
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn](INFO): Running loop #5
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn] Running Loop=5
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:04:18.387Z,1748552658.387 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:04:20.400Z,1748552660.400 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210407.00,A,3648.16153,N,12147.28760,W,0.097,10.88,290525,,,D*4C
2025-05-29T21:04:20.402Z,1748552660.402 [NAL9602](INFO): GPS fix at 20250529T210407: (36.802692, -121.788127)
2025-05-29T21:04:20.412Z,1748552660.412 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:04:20.412Z,1748552660.412 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:04:27.987Z,1748552667.987 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0016.lzma
2025-05-29T21:04:28.990Z,1748552668.990 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0016.lzma.bak
2025-05-29T21:04:28.990Z,1748552668.990 [DataOverHttps](INFO): SBD MOMSN=25034427
2025-05-29T21:04:45.009Z,1748552685.009 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20250529T203215/Express0017.lzma
2025-05-29T21:04:46.010Z,1748552686.010 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0017.lzma.bak
2025-05-29T21:04:46.011Z,1748552686.011 [DataOverHttps](INFO): SBD MOMSN=25034430
2025-05-29T21:04:47.878Z,1748552687.878 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:04:47.878Z,1748552687.878 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:04:47.878Z,1748552687.878 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:04:53.119Z,1748552693.119 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T21:08:23.673Z,1748552903.673 [CommandExec](IMPORTANT): got command gfscan
2025-05-29T21:08:23.690Z,1748552903.690 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-29T21:08:28.090Z,1748552908.090 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004172
CHAN A1 (24V): 0.003874
CHAN A2 (12V): -0.009001
CHAN A3 (5V): -0.010950
CHAN B0 (3.3V): -0.002868
CHAN B1 (3.15aV): -0.002492
CHAN B2 (3.15bV): -0.001508
CHAN B3 (GND): -0.002164
OPEN: 0.012189
Full Scale: +/- 1 mA
2025-05-29T21:08:31.372Z,1748552911.372 [CommandExec](IMPORTANT): got command failComponent
2025-05-29T21:08:31.373Z,1748552911.373 [CommandExec](IMPORTANT): Failed components:
2025-05-29T21:08:31.373Z,1748552911.373 [CommandExec](IMPORTANT): No failed Components.
2025-05-29T21:09:48.491Z,1748552988.491 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:09:48.491Z,1748552988.491 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:09:48.491Z,1748552988.491 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:09:48.491Z,1748552988.491 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:09:48.877Z,1748552988.877 [Default:CheckIn:D] Stopped
2025-05-29T21:09:48.877Z,1748552988.877 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:09:49.292Z,1748552989.292 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  32.352795 min 
2025-05-29T21:09:49.292Z,1748552989.292 [Default:CheckIn:E] Stopped
2025-05-29T21:09:49.292Z,1748552989.292 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:09:49.292Z,1748552989.292 [Default:CheckIn] Stopped
2025-05-29T21:09:49.292Z,1748552989.292 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:09:49.292Z,1748552989.292 [Default:CheckIn](INFO): Running loop #6
2025-05-29T21:09:49.293Z,1748552989.293 [Default:CheckIn] Running Loop=6
2025-05-29T21:09:49.293Z,1748552989.293 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:09:49.293Z,1748552989.293 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:09:51.290Z,1748552991.290 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210937.00,A,3648.16082,N,12147.28616,W,0.117,10.88,290525,,,D*46
2025-05-29T21:09:51.292Z,1748552991.292 [NAL9602](INFO): GPS fix at 20250529T210937: (36.802680, -121.788103)
2025-05-29T21:09:51.303Z,1748552991.303 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:09:51.303Z,1748552991.303 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:09:58.399Z,1748552998.399 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0019.lzma
2025-05-29T21:09:59.402Z,1748552999.402 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0019.lzma.bak
2025-05-29T21:09:59.402Z,1748552999.402 [DataOverHttps](INFO): SBD MOMSN=25034446
2025-05-29T21:10:15.328Z,1748553015.328 [DataOverHttps](INFO): Sending 417 bytes from file Logs/20250529T203215/Express0020.lzma
2025-05-29T21:10:16.330Z,1748553016.330 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0020.lzma.bak
2025-05-29T21:10:16.330Z,1748553016.330 [DataOverHttps](INFO): SBD MOMSN=25034449
2025-05-29T21:10:17.963Z,1748553017.963 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:10:17.964Z,1748553017.964 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:10:17.964Z,1748553017.964 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:10:21.989Z,1748553021.989 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T21:10:22.072Z,1748553022.072 [NAL9602](ERROR): received: 
+CSQ:0

OK746, 2, 0, 0, 0

OK
2025-05-29T21:14:53.894Z,1748553293.894 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T21:15:18.549Z,1748553318.549 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:15:18.549Z,1748553318.549 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:15:18.549Z,1748553318.549 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:15:18.549Z,1748553318.549 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:15:18.965Z,1748553318.965 [Default:CheckIn:D] Stopped
2025-05-29T21:15:18.965Z,1748553318.965 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  37.854256 min 
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn:E] Stopped
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn] Stopped
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn](INFO): Running loop #7
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn] Running Loop=7
2025-05-29T21:15:19.351Z,1748553319.351 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:15:19.352Z,1748553319.352 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:15:21.367Z,1748553321.367 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211508.00,A,3648.16301,N,12147.28561,W,0.097,10.88,290525,,,D*45
2025-05-29T21:15:21.369Z,1748553321.369 [NAL9602](INFO): GPS fix at 20250529T211508: (36.802717, -121.788094)
2025-05-29T21:15:21.380Z,1748553321.380 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:15:21.380Z,1748553321.380 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:15:29.067Z,1748553329.067 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250529T203215/Courier0022.lzma
2025-05-29T21:15:30.070Z,1748553330.070 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0022.lzma.bak
2025-05-29T21:15:30.070Z,1748553330.070 [DataOverHttps](INFO): SBD MOMSN=25034531
2025-05-29T21:15:46.853Z,1748553346.853 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20250529T203215/Express0023.lzma
2025-05-29T21:15:47.854Z,1748553347.854 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0023.lzma.bak
2025-05-29T21:15:47.855Z,1748553347.855 [DataOverHttps](INFO): SBD MOMSN=25034534
2025-05-29T21:15:49.255Z,1748553349.255 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:15:49.255Z,1748553349.255 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:15:49.255Z,1748553349.255 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:15:54.095Z,1748553354.095 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T21:20:49.829Z,1748553649.829 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:20:49.829Z,1748553649.829 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:20:49.829Z,1748553649.829 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:20:49.829Z,1748553649.829 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:20:50.227Z,1748553650.227 [Default:CheckIn:D] Stopped
2025-05-29T21:20:50.227Z,1748553650.227 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:20:50.634Z,1748553650.634 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  43.375293 min 
2025-05-29T21:20:50.634Z,1748553650.634 [Default:CheckIn:E] Stopped
2025-05-29T21:20:50.634Z,1748553650.634 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:20:50.634Z,1748553650.634 [Default:CheckIn] Stopped
2025-05-29T21:20:50.634Z,1748553650.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:20:50.635Z,1748553650.635 [Default:CheckIn](INFO): Running loop #8
2025-05-29T21:20:50.635Z,1748553650.635 [Default:CheckIn] Running Loop=8
2025-05-29T21:20:50.635Z,1748553650.635 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:20:50.635Z,1748553650.635 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:20:52.647Z,1748553652.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212039.00,A,3648.16117,N,12147.28464,W,0.039,100.59,290525,,,D*78
2025-05-29T21:20:52.649Z,1748553652.649 [NAL9602](INFO): GPS fix at 20250529T212039: (36.802686, -121.788077)
2025-05-29T21:20:52.660Z,1748553652.660 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:20:52.660Z,1748553652.660 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:21:00.551Z,1748553660.551 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0025.lzma
2025-05-29T21:21:01.554Z,1748553661.554 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0025.lzma.bak
2025-05-29T21:21:01.554Z,1748553661.554 [DataOverHttps](INFO): SBD MOMSN=25034554
2025-05-29T21:21:17.372Z,1748553677.372 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250529T203215/Express0026.lzma
2025-05-29T21:21:18.374Z,1748553678.374 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0026.lzma.bak
2025-05-29T21:21:18.374Z,1748553678.374 [DataOverHttps](INFO): SBD MOMSN=25034557
2025-05-29T21:21:19.728Z,1748553679.728 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:21:19.728Z,1748553679.728 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:21:19.728Z,1748553679.728 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:21:23.345Z,1748553683.345 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T21:21:23.424Z,1748553683.424 [NAL9602](ERROR): received: 
+CSQ:0

OK746, 2, 0, 0, 0

OK
2025-05-29T21:25:54.839Z,1748553954.839 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T21:26:20.311Z,1748553980.311 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:26:20.311Z,1748553980.311 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:26:20.311Z,1748553980.311 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:26:20.311Z,1748553980.311 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:26:20.705Z,1748553980.705 [Default:CheckIn:D] Stopped
2025-05-29T21:26:20.705Z,1748553980.705 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:26:21.111Z,1748553981.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  48.883252 min 
2025-05-29T21:26:21.111Z,1748553981.111 [Default:CheckIn:E] Stopped
2025-05-29T21:26:21.111Z,1748553981.111 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:26:21.111Z,1748553981.111 [Default:CheckIn] Stopped
2025-05-29T21:26:21.111Z,1748553981.111 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:26:21.111Z,1748553981.111 [Default:CheckIn](INFO): Running loop #9
2025-05-29T21:26:21.112Z,1748553981.112 [Default:CheckIn] Running Loop=9
2025-05-29T21:26:21.112Z,1748553981.112 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:26:21.112Z,1748553981.112 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:26:23.114Z,1748553983.114 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212609.00,A,3648.16345,N,12147.28294,W,0.603,100.59,290525,,,D*7E
2025-05-29T21:26:23.117Z,1748553983.117 [NAL9602](INFO): GPS fix at 20250529T212609: (36.802724, -121.788049)
2025-05-29T21:26:23.127Z,1748553983.127 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:26:23.127Z,1748553983.127 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:26:30.867Z,1748553990.867 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0028.lzma
2025-05-29T21:26:31.870Z,1748553991.870 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0028.lzma.bak
2025-05-29T21:26:31.870Z,1748553991.870 [DataOverHttps](INFO): SBD MOMSN=25034625
2025-05-29T21:26:49.608Z,1748554009.608 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20250529T203215/Express0029.lzma
2025-05-29T21:26:50.610Z,1748554010.610 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0029.lzma.bak
2025-05-29T21:26:50.610Z,1748554010.610 [DataOverHttps](INFO): SBD MOMSN=25034628
2025-05-29T21:26:52.217Z,1748554012.217 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:26:52.217Z,1748554012.217 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:26:52.217Z,1748554012.217 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:26:55.042Z,1748554015.042 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T21:31:52.841Z,1748554312.841 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:31:52.841Z,1748554312.841 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:31:52.841Z,1748554312.841 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:31:52.841Z,1748554312.841 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:31:53.226Z,1748554313.226 [Default:CheckIn:D] Stopped
2025-05-29T21:31:53.226Z,1748554313.226 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:31:53.633Z,1748554313.633 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  54.425277 min 
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn:E] Stopped
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn] Stopped
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn](INFO): Running loop #10
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn] Running Loop=10
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:31:53.634Z,1748554313.634 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:31:55.642Z,1748554315.642 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213142.00,A,3648.16281,N,12147.28273,W,1.283,69.54,290525,,,D*49
2025-05-29T21:31:55.655Z,1748554315.655 [NAL9602](INFO): GPS fix at 20250529T213142: (36.802714, -121.788045)
2025-05-29T21:31:55.667Z,1748554315.667 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:31:55.667Z,1748554315.667 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:32:04.187Z,1748554324.187 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0031.lzma
2025-05-29T21:32:05.190Z,1748554325.190 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0031.lzma.bak
2025-05-29T21:32:05.190Z,1748554325.190 [DataOverHttps](INFO): SBD MOMSN=25034645
2025-05-29T21:32:21.092Z,1748554341.092 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250529T203215/Express0032.lzma
2025-05-29T21:32:22.094Z,1748554342.094 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0032.lzma.bak
2025-05-29T21:32:22.094Z,1748554342.094 [DataOverHttps](INFO): SBD MOMSN=25034648
2025-05-29T21:32:23.536Z,1748554343.536 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:32:23.536Z,1748554343.536 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:32:23.536Z,1748554343.536 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:32:26.349Z,1748554346.349 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T21:32:26.428Z,1748554346.428 [NAL9602](ERROR): received: 
+CSQ:0

OK746, 2, 0, 0, 0

OK
2025-05-29T21:34:34.824Z,1748554474.824 [NAL9602](INFO): SBD MO Status=0, MOMSN=20746, MT Status=0, MTMSN=0
2025-05-29T21:34:34.825Z,1748554474.825 [NAL9602](INFO): No messages in MT queue
2025-05-29T21:35:05.520Z,1748554505.520 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T21:37:24.104Z,1748554644.104 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:37:24.104Z,1748554644.104 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:37:24.104Z,1748554644.104 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:37:24.105Z,1748554644.105 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:37:24.575Z,1748554644.575 [Default:CheckIn:D] Stopped
2025-05-29T21:37:24.575Z,1748554644.575 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:37:24.997Z,1748554644.997 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  59.947762 min 
2025-05-29T21:37:24.997Z,1748554644.997 [Default:CheckIn:E] Stopped
2025-05-29T21:37:24.997Z,1748554644.997 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:37:24.998Z,1748554644.998 [Default:CheckIn] Stopped
2025-05-29T21:37:24.998Z,1748554644.998 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:37:24.998Z,1748554644.998 [Default:CheckIn](INFO): Running loop #11
2025-05-29T21:37:24.998Z,1748554644.998 [Default:CheckIn] Running Loop=11
2025-05-29T21:37:24.998Z,1748554644.998 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:37:24.998Z,1748554644.998 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:37:26.922Z,1748554646.922 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213713.00,A,3648.16486,N,12147.28214,W,0.175,144.91,290525,,,D*77
2025-05-29T21:37:26.925Z,1748554646.925 [NAL9602](INFO): GPS fix at 20250529T213713: (36.802748, -121.788036)
2025-05-29T21:37:26.935Z,1748554646.935 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:37:26.935Z,1748554646.935 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:37:34.715Z,1748554654.715 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0034.lzma
2025-05-29T21:37:35.718Z,1748554655.718 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0034.lzma.bak
2025-05-29T21:37:35.718Z,1748554655.718 [DataOverHttps](INFO): SBD MOMSN=25034722
2025-05-29T21:37:51.712Z,1748554671.712 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250529T203215/Express0035.lzma
2025-05-29T21:37:52.714Z,1748554672.714 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0035.lzma.bak
2025-05-29T21:37:52.714Z,1748554672.714 [DataOverHttps](INFO): SBD MOMSN=25034725
2025-05-29T21:37:54.038Z,1748554674.038 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:37:54.038Z,1748554674.038 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:37:54.038Z,1748554674.038 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:42:29.129Z,1748554949.129 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T21:42:54.590Z,1748554974.590 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:42:54.590Z,1748554974.590 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:42:54.590Z,1748554974.590 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:42:54.591Z,1748554974.591 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:42:54.992Z,1748554974.992 [Default:CheckIn:D] Stopped
2025-05-29T21:42:54.993Z,1748554974.993 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:42:55.403Z,1748554975.403 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  65.454700 min 
2025-05-29T21:42:55.404Z,1748554975.404 [Default:CheckIn:E] Stopped
2025-05-29T21:42:55.404Z,1748554975.404 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:42:55.404Z,1748554975.404 [Default:CheckIn] Stopped
2025-05-29T21:42:55.404Z,1748554975.404 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:42:55.404Z,1748554975.404 [Default:CheckIn](INFO): Running loop #12
2025-05-29T21:42:55.404Z,1748554975.404 [Default:CheckIn] Running Loop=12
2025-05-29T21:42:55.404Z,1748554975.404 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:42:55.405Z,1748554975.405 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:42:57.408Z,1748554977.408 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214244.00,A,3648.16424,N,12147.28356,W,0.019,144.91,290525,,,D*73
2025-05-29T21:42:57.410Z,1748554977.410 [NAL9602](INFO): GPS fix at 20250529T214244: (36.802737, -121.788059)
2025-05-29T21:42:57.446Z,1748554977.446 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:42:57.446Z,1748554977.446 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:43:04.551Z,1748554984.551 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250529T203215/Courier0037.lzma
2025-05-29T21:43:05.554Z,1748554985.554 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0037.lzma.bak
2025-05-29T21:43:05.554Z,1748554985.554 [DataOverHttps](INFO): SBD MOMSN=25034738
2025-05-29T21:43:21.965Z,1748555001.965 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20250529T203215/Express0038.lzma
2025-05-29T21:43:22.966Z,1748555002.966 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0038.lzma.bak
2025-05-29T21:43:22.966Z,1748555002.966 [DataOverHttps](INFO): SBD MOMSN=25034748
2025-05-29T21:43:24.499Z,1748555004.499 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:43:24.499Z,1748555004.499 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:43:24.500Z,1748555004.500 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:43:30.141Z,1748555010.141 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T21:47:23.488Z,1748555243.488 [BPC1](ERROR): BPC1A: No match for serial number FFFF in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2025-05-29T21:48:24.901Z,1748555304.901 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:48:24.901Z,1748555304.901 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:48:24.901Z,1748555304.901 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:48:24.902Z,1748555304.902 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:48:25.316Z,1748555305.316 [Default:CheckIn:D] Stopped
2025-05-29T21:48:25.316Z,1748555305.316 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:48:25.706Z,1748555305.706 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  70.960116 min 
2025-05-29T21:48:25.706Z,1748555305.706 [Default:CheckIn:E] Stopped
2025-05-29T21:48:25.706Z,1748555305.706 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:48:25.706Z,1748555305.706 [Default:CheckIn] Stopped
2025-05-29T21:48:25.706Z,1748555305.706 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:48:25.707Z,1748555305.707 [Default:CheckIn](INFO): Running loop #13
2025-05-29T21:48:25.707Z,1748555305.707 [Default:CheckIn] Running Loop=13
2025-05-29T21:48:25.707Z,1748555305.707 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:48:25.707Z,1748555305.707 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:48:27.780Z,1748555307.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214814.00,A,3648.16534,N,12147.28297,W,0.058,18.15,290525,,,D*41
2025-05-29T21:48:27.782Z,1748555307.782 [NAL9602](INFO): GPS fix at 20250529T214814: (36.802756, -121.788049)
2025-05-29T21:48:27.793Z,1748555307.793 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:48:27.793Z,1748555307.793 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:48:35.659Z,1748555315.659 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0040.lzma
2025-05-29T21:48:36.662Z,1748555316.662 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0040.lzma.bak
2025-05-29T21:48:36.662Z,1748555316.662 [DataOverHttps](INFO): SBD MOMSN=25034810
2025-05-29T21:48:40.666Z,1748555320.666 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-29T21:48:40.667Z,1748555320.667 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-05-29T21:48:40.668Z,1748555320.668 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2025-05-29T21:48:40.676Z,1748555320.676 [BPC1](INFO): Received data from all battery sticks.
2025-05-29T21:48:52.836Z,1748555332.836 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250529T203215/Express0041.lzma
2025-05-29T21:48:53.838Z,1748555333.838 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0041.lzma.bak
2025-05-29T21:48:53.838Z,1748555333.838 [DataOverHttps](INFO): SBD MOMSN=25034819
2025-05-29T21:48:55.216Z,1748555335.216 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:48:55.216Z,1748555335.216 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:48:55.216Z,1748555335.216 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:48:58.429Z,1748555338.429 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T21:48:58.504Z,1748555338.504 [NAL9602](ERROR): received: 
+CSQ:0

OK746, 0, 0, 0, 0

OK
2025-05-29T21:49:38.053Z,1748555378.053 [NAL9602](INFO): SBD MO Status=2, MOMSN=20747, MT Status=2, MTMSN=0
2025-05-29T21:49:38.053Z,1748555378.053 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T21:51:45.730Z,1748555505.730 [NAL9602](INFO): SBD MO Status=0, MOMSN=20747, MT Status=0, MTMSN=0
2025-05-29T21:51:45.730Z,1748555505.730 [NAL9602](INFO): No messages in MT queue
2025-05-29T21:52:16.419Z,1748555536.419 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T21:53:55.828Z,1748555635.828 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:53:55.828Z,1748555635.828 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:53:55.828Z,1748555635.828 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:53:55.828Z,1748555635.828 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:53:56.237Z,1748555636.237 [Default:CheckIn:D] Stopped
2025-05-29T21:53:56.237Z,1748555636.237 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:53:56.652Z,1748555636.652 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  76.475456 min 
2025-05-29T21:53:56.652Z,1748555636.652 [Default:CheckIn:E] Stopped
2025-05-29T21:53:56.653Z,1748555636.653 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:53:56.653Z,1748555636.653 [Default:CheckIn] Stopped
2025-05-29T21:53:56.653Z,1748555636.653 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:53:56.653Z,1748555636.653 [Default:CheckIn](INFO): Running loop #14
2025-05-29T21:53:56.653Z,1748555636.653 [Default:CheckIn] Running Loop=14
2025-05-29T21:53:56.653Z,1748555636.653 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:53:56.653Z,1748555636.653 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:53:58.650Z,1748555638.650 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215345.00,A,3648.16517,N,12147.28394,W,3.188,138.55,290525,,,D*74
2025-05-29T21:53:58.652Z,1748555638.652 [NAL9602](INFO): GPS fix at 20250529T215345: (36.802753, -121.788066)
2025-05-29T21:53:58.662Z,1748555638.662 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:53:58.662Z,1748555638.662 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:54:06.092Z,1748555646.092 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20250529T203215/Courier0043.lzma
2025-05-29T21:54:07.094Z,1748555647.094 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0043.lzma.bak
2025-05-29T21:54:07.094Z,1748555647.094 [DataOverHttps](INFO): SBD MOMSN=25034873
2025-05-29T21:54:22.924Z,1748555662.924 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250529T203215/Express0044.lzma
2025-05-29T21:54:23.926Z,1748555663.926 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0044.lzma.bak
2025-05-29T21:54:23.926Z,1748555663.926 [DataOverHttps](INFO): SBD MOMSN=25034881
2025-05-29T21:54:25.330Z,1748555665.330 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:54:25.331Z,1748555665.331 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:54:25.331Z,1748555665.331 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T21:54:37.031Z,1748555677.031 [NAL9602](INFO): SBD MO Status=2, MOMSN=20748, MT Status=2, MTMSN=0
2025-05-29T21:54:37.031Z,1748555677.031 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T21:55:41.672Z,1748555741.672 [NAL9602](INFO): SBD MO Status=2, MOMSN=20748, MT Status=2, MTMSN=0
2025-05-29T21:55:41.672Z,1748555741.672 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T21:59:00.862Z,1748555940.862 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T21:59:25.917Z,1748555965.917 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T21:59:25.917Z,1748555965.917 [Default:CheckIn:C.Wait] Stopped
2025-05-29T21:59:25.917Z,1748555965.917 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T21:59:25.917Z,1748555965.917 [Default:CheckIn:D] Running Loop=1
2025-05-29T21:59:26.335Z,1748555966.335 [Default:CheckIn:D] Stopped
2025-05-29T21:59:26.335Z,1748555966.335 [Default:CheckIn:E] Running Loop=1
2025-05-29T21:59:26.730Z,1748555966.730 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  81.977091 min 
2025-05-29T21:59:26.730Z,1748555966.730 [Default:CheckIn:E] Stopped
2025-05-29T21:59:26.730Z,1748555966.730 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T21:59:26.730Z,1748555966.730 [Default:CheckIn] Stopped
2025-05-29T21:59:26.730Z,1748555966.730 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T21:59:26.731Z,1748555966.731 [Default:CheckIn](INFO): Running loop #15
2025-05-29T21:59:26.731Z,1748555966.731 [Default:CheckIn] Running Loop=15
2025-05-29T21:59:26.731Z,1748555966.731 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T21:59:26.731Z,1748555966.731 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T21:59:28.734Z,1748555968.734 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215915.00,A,3648.16631,N,12147.28297,W,0.136,88.10,290525,,,D*43
2025-05-29T21:59:28.736Z,1748555968.736 [NAL9602](INFO): GPS fix at 20250529T215915: (36.802772, -121.788049)
2025-05-29T21:59:28.747Z,1748555968.747 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T21:59:28.747Z,1748555968.747 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T21:59:37.119Z,1748555977.119 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0046.lzma
2025-05-29T21:59:38.122Z,1748555978.122 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0046.lzma.bak
2025-05-29T21:59:38.122Z,1748555978.122 [DataOverHttps](INFO): SBD MOMSN=25034894
2025-05-29T21:59:54.892Z,1748555994.892 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20250529T203215/Express0047.lzma
2025-05-29T21:59:55.894Z,1748555995.894 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0047.lzma.bak
2025-05-29T21:59:55.894Z,1748555995.894 [DataOverHttps](INFO): SBD MOMSN=25034897
2025-05-29T21:59:57.218Z,1748555997.218 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T21:59:57.218Z,1748555997.218 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T21:59:57.218Z,1748555997.218 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T22:00:01.233Z,1748556001.233 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T22:04:57.795Z,1748556297.795 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T22:04:57.795Z,1748556297.795 [Default:CheckIn:C.Wait] Stopped
2025-05-29T22:04:57.795Z,1748556297.795 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T22:04:57.795Z,1748556297.795 [Default:CheckIn:D] Running Loop=1
2025-05-29T22:04:58.186Z,1748556298.186 [Default:CheckIn:D] Stopped
2025-05-29T22:04:58.186Z,1748556298.186 [Default:CheckIn:E] Running Loop=1
2025-05-29T22:04:58.591Z,1748556298.591 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  87.507943 min 
2025-05-29T22:04:58.591Z,1748556298.591 [Default:CheckIn:E] Stopped
2025-05-29T22:04:58.592Z,1748556298.592 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T22:04:58.592Z,1748556298.592 [Default:CheckIn] Stopped
2025-05-29T22:04:58.592Z,1748556298.592 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T22:04:58.592Z,1748556298.592 [Default:CheckIn](INFO): Running loop #16
2025-05-29T22:04:58.592Z,1748556298.592 [Default:CheckIn] Running Loop=16
2025-05-29T22:04:58.592Z,1748556298.592 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T22:04:58.592Z,1748556298.592 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T22:05:00.610Z,1748556300.610 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220447.00,A,3648.16576,N,12147.28392,W,0.272,177.40,290525,,,D*7C
2025-05-29T22:05:00.613Z,1748556300.613 [NAL9602](INFO): GPS fix at 20250529T220447: (36.802763, -121.788065)
2025-05-29T22:05:00.650Z,1748556300.650 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T22:05:00.651Z,1748556300.651 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T22:05:08.304Z,1748556308.304 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0049.lzma
2025-05-29T22:05:09.306Z,1748556309.306 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0049.lzma.bak
2025-05-29T22:05:09.306Z,1748556309.306 [DataOverHttps](INFO): SBD MOMSN=25034951
2025-05-29T22:05:25.228Z,1748556325.228 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250529T203215/Express0050.lzma
2025-05-29T22:05:26.230Z,1748556326.230 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0050.lzma.bak
2025-05-29T22:05:26.230Z,1748556326.230 [DataOverHttps](INFO): SBD MOMSN=25034954
2025-05-29T22:05:27.693Z,1748556327.693 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T22:05:27.693Z,1748556327.693 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T22:05:27.693Z,1748556327.693 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T22:05:31.345Z,1748556331.345 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T22:05:31.428Z,1748556331.428 [NAL9602](ERROR): received: 
+CSQ:0

OK748, 2, 0, 0, 0

OK
2025-05-29T22:07:16.359Z,1748556436.359 [NAL9602](INFO): SBD MO Status=0, MOMSN=20748, MT Status=0, MTMSN=0
2025-05-29T22:07:16.359Z,1748556436.359 [NAL9602](INFO): No messages in MT queue
2025-05-29T22:07:47.061Z,1748556467.061 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T22:10:28.322Z,1748556628.322 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T22:10:28.322Z,1748556628.322 [Default:CheckIn:C.Wait] Stopped
2025-05-29T22:10:28.322Z,1748556628.322 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T22:10:28.322Z,1748556628.322 [Default:CheckIn:D] Running Loop=1
2025-05-29T22:10:28.729Z,1748556628.729 [Default:CheckIn:D] Stopped
2025-05-29T22:10:28.729Z,1748556628.729 [Default:CheckIn:E] Running Loop=1
2025-05-29T22:10:29.126Z,1748556629.126 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  93.016992 min 
2025-05-29T22:10:29.126Z,1748556629.126 [Default:CheckIn:E] Stopped
2025-05-29T22:10:29.127Z,1748556629.127 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T22:10:29.127Z,1748556629.127 [Default:CheckIn] Stopped
2025-05-29T22:10:29.127Z,1748556629.127 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T22:10:29.127Z,1748556629.127 [Default:CheckIn](INFO): Running loop #17
2025-05-29T22:10:29.127Z,1748556629.127 [Default:CheckIn] Running Loop=17
2025-05-29T22:10:29.127Z,1748556629.127 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T22:10:29.127Z,1748556629.127 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T22:10:31.129Z,1748556631.129 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221017.00,A,3648.16363,N,12147.28185,W,0.097,49.82,290525,,,D*41
2025-05-29T22:10:31.150Z,1748556631.150 [NAL9602](INFO): GPS fix at 20250529T221017: (36.802727, -121.788031)
2025-05-29T22:10:31.169Z,1748556631.169 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T22:10:31.169Z,1748556631.169 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T22:10:42.908Z,1748556642.908 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250529T203215/Courier0052.lzma
2025-05-29T22:10:43.910Z,1748556643.910 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0052.lzma.bak
2025-05-29T22:10:43.910Z,1748556643.910 [DataOverHttps](INFO): SBD MOMSN=25034964
2025-05-29T22:11:10.776Z,1748556670.776 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250529T203215/Express0053.lzma
2025-05-29T22:11:11.778Z,1748556671.778 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0053.lzma.bak
2025-05-29T22:11:11.778Z,1748556671.778 [DataOverHttps](INFO): SBD MOMSN=25034967
2025-05-29T22:11:13.435Z,1748556673.435 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T22:11:13.435Z,1748556673.435 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T22:11:13.435Z,1748556673.435 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T22:14:54.366Z,1748556894.366 [NAL9602](INFO): SBD MO Status=0, MOMSN=20749, MT Status=0, MTMSN=0
2025-05-29T22:14:54.366Z,1748556894.366 [NAL9602](INFO): No messages in MT queue
2025-05-29T22:15:25.074Z,1748556925.074 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T22:16:13.969Z,1748556973.969 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T22:16:13.969Z,1748556973.969 [Default:CheckIn:C.Wait] Stopped
2025-05-29T22:16:13.969Z,1748556973.969 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T22:16:13.969Z,1748556973.969 [Default:CheckIn:D] Running Loop=1
2025-05-29T22:16:14.389Z,1748556974.389 [Default:CheckIn:D] Stopped
2025-05-29T22:16:14.389Z,1748556974.389 [Default:CheckIn:E] Running Loop=1
2025-05-29T22:16:14.779Z,1748556974.779 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  98.777995 min 
2025-05-29T22:16:14.779Z,1748556974.779 [Default:CheckIn:E] Stopped
2025-05-29T22:16:14.779Z,1748556974.779 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T22:16:14.779Z,1748556974.779 [Default:CheckIn] Stopped
2025-05-29T22:16:14.779Z,1748556974.779 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T22:16:14.780Z,1748556974.780 [Default:CheckIn](INFO): Running loop #18
2025-05-29T22:16:14.780Z,1748556974.780 [Default:CheckIn] Running Loop=18
2025-05-29T22:16:14.780Z,1748556974.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T22:16:14.780Z,1748556974.780 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T22:16:16.783Z,1748556976.783 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221603.00,A,3648.16394,N,12147.28287,W,0.097,102.35,290525,,,D*79
2025-05-29T22:16:16.786Z,1748556976.786 [NAL9602](INFO): GPS fix at 20250529T221603: (36.802732, -121.788048)
2025-05-29T22:16:16.796Z,1748556976.796 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T22:16:16.796Z,1748556976.796 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T22:16:24.619Z,1748556984.619 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0055.lzma
2025-05-29T22:16:25.622Z,1748556985.622 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0055.lzma.bak
2025-05-29T22:16:25.622Z,1748556985.622 [DataOverHttps](INFO): SBD MOMSN=25035032
2025-05-29T22:16:41.426Z,1748557001.426 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:16:41.426Z,1748557001.426 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:16:41.444Z,1748557001.444 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250529T203215/Express0056.lzma
2025-05-29T22:16:42.446Z,1748557002.446 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0056.lzma.bak
2025-05-29T22:16:42.446Z,1748557002.446 [DataOverHttps](INFO): SBD MOMSN=25035035
2025-05-29T22:16:43.870Z,1748557003.870 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T22:16:43.870Z,1748557003.870 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T22:16:43.870Z,1748557003.870 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T22:16:57.187Z,1748557017.187 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:16:57.187Z,1748557017.187 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:17:26.273Z,1748557046.273 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:17:26.273Z,1748557046.273 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:17:56.170Z,1748557076.170 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:17:56.170Z,1748557076.170 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:18:42.225Z,1748557122.225 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:18:42.225Z,1748557122.225 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:19:02.428Z,1748557142.428 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:19:02.428Z,1748557142.428 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:21:19.043Z,1748557279.043 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T22:21:44.517Z,1748557304.517 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T22:21:44.517Z,1748557304.517 [Default:CheckIn:C.Wait] Stopped
2025-05-29T22:21:44.517Z,1748557304.517 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T22:21:44.517Z,1748557304.517 [Default:CheckIn:D] Running Loop=1
2025-05-29T22:21:44.902Z,1748557304.902 [Default:CheckIn:D] Stopped
2025-05-29T22:21:44.902Z,1748557304.902 [Default:CheckIn:E] Running Loop=1
2025-05-29T22:21:45.315Z,1748557305.315 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  104.286532 min 
2025-05-29T22:21:45.315Z,1748557305.315 [Default:CheckIn:E] Stopped
2025-05-29T22:21:45.315Z,1748557305.315 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T22:21:45.315Z,1748557305.315 [Default:CheckIn] Stopped
2025-05-29T22:21:45.315Z,1748557305.315 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T22:21:45.315Z,1748557305.315 [Default:CheckIn](INFO): Running loop #19
2025-05-29T22:21:45.315Z,1748557305.315 [Default:CheckIn] Running Loop=19
2025-05-29T22:21:45.316Z,1748557305.316 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T22:21:45.316Z,1748557305.316 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T22:21:47.323Z,1748557307.323 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222133.00,A,3648.16268,N,12147.28149,W,0.272,96.90,290525,,,D*47
2025-05-29T22:21:47.326Z,1748557307.326 [NAL9602](INFO): GPS fix at 20250529T222133: (36.802711, -121.788025)
2025-05-29T22:21:47.337Z,1748557307.337 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T22:21:47.337Z,1748557307.337 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T22:21:55.287Z,1748557315.287 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0058.lzma
2025-05-29T22:21:56.290Z,1748557316.290 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0058.lzma.bak
2025-05-29T22:21:56.290Z,1748557316.290 [DataOverHttps](INFO): SBD MOMSN=25035045
2025-05-29T22:22:12.137Z,1748557332.137 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20250529T203215/Express0059.lzma
2025-05-29T22:22:13.138Z,1748557333.138 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0059.lzma.bak
2025-05-29T22:22:13.138Z,1748557333.138 [DataOverHttps](INFO): SBD MOMSN=25035048
2025-05-29T22:22:14.393Z,1748557334.393 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T22:22:14.393Z,1748557334.393 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T22:22:14.393Z,1748557334.393 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T22:22:20.049Z,1748557340.049 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T22:27:14.976Z,1748557634.976 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T22:27:14.976Z,1748557634.976 [Default:CheckIn:C.Wait] Stopped
2025-05-29T22:27:14.976Z,1748557634.976 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T22:27:14.976Z,1748557634.976 [Default:CheckIn:D] Running Loop=1
2025-05-29T22:27:15.393Z,1748557635.393 [Default:CheckIn:D] Stopped
2025-05-29T22:27:15.393Z,1748557635.393 [Default:CheckIn:E] Running Loop=1
2025-05-29T22:27:15.779Z,1748557635.779 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  109.794718 min 
2025-05-29T22:27:15.779Z,1748557635.779 [Default:CheckIn:E] Stopped
2025-05-29T22:27:15.779Z,1748557635.779 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T22:27:15.779Z,1748557635.779 [Default:CheckIn] Stopped
2025-05-29T22:27:15.780Z,1748557635.780 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T22:27:15.780Z,1748557635.780 [Default:CheckIn](INFO): Running loop #20
2025-05-29T22:27:15.780Z,1748557635.780 [Default:CheckIn] Running Loop=20
2025-05-29T22:27:15.780Z,1748557635.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T22:27:15.780Z,1748557635.780 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T22:27:17.795Z,1748557637.795 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222704.00,A,3648.16586,N,12147.27980,W,0.311,96.90,290525,,,D*44
2025-05-29T22:27:17.797Z,1748557637.797 [NAL9602](INFO): GPS fix at 20250529T222704: (36.802764, -121.787997)
2025-05-29T22:27:17.808Z,1748557637.808 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T22:27:17.808Z,1748557637.808 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T22:27:25.335Z,1748557645.335 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250529T203215/Courier0061.lzma
2025-05-29T22:27:26.338Z,1748557646.338 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0061.lzma.bak
2025-05-29T22:27:26.338Z,1748557646.338 [DataOverHttps](INFO): SBD MOMSN=25035110
2025-05-29T22:27:42.506Z,1748557662.506 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250529T203215/Express0062.lzma
2025-05-29T22:27:43.506Z,1748557663.506 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0062.lzma.bak
2025-05-29T22:27:43.506Z,1748557663.506 [DataOverHttps](INFO): SBD MOMSN=25035113
2025-05-29T22:27:45.276Z,1748557665.276 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T22:27:45.276Z,1748557665.276 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T22:27:45.276Z,1748557665.276 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T22:27:48.497Z,1748557668.497 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-05-29T22:27:48.580Z,1748557668.580 [NAL9602](ERROR): received: 
+CSQ:0

OK750, 2, 0, 0, 0

OK
2025-05-29T22:28:20.010Z,1748557700.010 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:28:20.011Z,1748557700.011 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:29:48.487Z,1748557788.487 [NAL9602](INFO): SBD MO Status=2, MOMSN=20750, MT Status=2, MTMSN=0
2025-05-29T22:29:48.487Z,1748557788.487 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-29T22:30:39.353Z,1748557839.353 [CommandExec](IMPORTANT): got command strobe off
2025-05-29T22:30:39.353Z,1748557839.353 [CommandExec](IMPORTANT): Deactivating strobe
2025-05-29T22:32:19.980Z,1748557939.980 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-29T22:32:45.851Z,1748557965.851 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-29T22:32:45.852Z,1748557965.852 [Default:CheckIn:C.Wait] Stopped
2025-05-29T22:32:45.852Z,1748557965.852 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T22:32:45.852Z,1748557965.852 [Default:CheckIn:D] Running Loop=1
2025-05-29T22:32:46.269Z,1748557966.269 [Default:CheckIn:D] Stopped
2025-05-29T22:32:46.269Z,1748557966.269 [Default:CheckIn:E] Running Loop=1
2025-05-29T22:32:46.654Z,1748557966.654 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  115.309318 min 
2025-05-29T22:32:46.654Z,1748557966.654 [Default:CheckIn:E] Stopped
2025-05-29T22:32:46.654Z,1748557966.654 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-29T22:32:46.654Z,1748557966.654 [Default:CheckIn] Stopped
2025-05-29T22:32:46.654Z,1748557966.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T22:32:46.654Z,1748557966.654 [Default:CheckIn](INFO): Running loop #21
2025-05-29T22:32:46.655Z,1748557966.655 [Default:CheckIn] Running Loop=21
2025-05-29T22:32:46.655Z,1748557966.655 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-29T22:32:46.655Z,1748557966.655 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-29T22:32:48.671Z,1748557968.671 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223235.00,A,3648.16869,N,12147.28616,W,0.117,125.36,290525,,,D*70
2025-05-29T22:32:48.674Z,1748557968.674 [NAL9602](INFO): GPS fix at 20250529T223235: (36.802811, -121.788103)
2025-05-29T22:32:48.684Z,1748557968.684 [Default:CheckIn:Read_GPS] Stopped
2025-05-29T22:32:48.684Z,1748557968.684 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-29T22:32:55.855Z,1748557975.855 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250529T203215/Courier0064.lzma
2025-05-29T22:32:56.858Z,1748557976.858 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Courier0064.lzma.bak
2025-05-29T22:32:56.858Z,1748557976.858 [DataOverHttps](INFO): SBD MOMSN=25035122
2025-05-29T22:33:13.256Z,1748557993.256 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20250529T203215/Express0065.lzma
2025-05-29T22:33:14.258Z,1748557994.258 [DataOverHttps](INFO): Moved sent file to Logs/20250529T203215/Express0065.lzma.bak
2025-05-29T22:33:14.258Z,1748557994.258 [DataOverHttps](INFO): SBD MOMSN=25035126
2025-05-29T22:33:15.750Z,1748557995.750 [Default:CheckIn:Read_Iridium] Stopped
2025-05-29T22:33:15.750Z,1748557995.750 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-29T22:33:15.750Z,1748557995.750 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-29T22:33:20.985Z,1748558000.985 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-29T22:34:34.313Z,1748558074.313 [CommandExec](IMPORTANT): got command quit
2025-05-29T22:34:35.316Z,1748558075.316 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2025-05-29T22:34:35.316Z,1748558075.316 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:35.316Z,1748558075.316 [CommandExec](INFO): Uninitializing the command executive.
2025-05-29T22:34:35.317Z,1748558075.317 [CommandExec](INFO): Uninitializing the command scheduler.
2025-05-29T22:34:35.317Z,1748558075.317 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:35.436Z,1748558075.436 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2025-05-29T22:34:35.436Z,1748558075.436 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-05-29T22:34:35.436Z,1748558075.436 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:35.437Z,1748558075.437 [NavChartDb](INFO): Join timeout helper Thread ID is 1888
2025-05-29T22:34:35.588Z,1748558075.588 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:35.588Z,1748558075.588 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:35.596Z,1748558075.596 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-05-29T22:34:35.596Z,1748558075.596 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:35.596Z,1748558075.596 [Radio_Surface](INFO): Join timeout helper Thread ID is 1889
2025-05-29T22:34:35.680Z,1748558075.680 [Radio_Surface](INFO): Powering down
2025-05-29T22:34:35.681Z,1748558075.681 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:35.681Z,1748558075.681 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:35.696Z,1748558075.696 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-05-29T22:34:35.696Z,1748558075.696 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:35.696Z,1748558075.696 [Onboard](INFO): Join timeout helper Thread ID is 1890
2025-05-29T22:34:36.476Z,1748558076.476 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-05-29T22:34:37.760Z,1748558077.760 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:37.760Z,1748558077.760 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:37.768Z,1748558077.768 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-05-29T22:34:37.768Z,1748558077.768 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:37.768Z,1748558077.768 [DataOverHttps](INFO): Join timeout helper Thread ID is 1891
2025-05-29T22:34:38.484Z,1748558078.484 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:38.484Z,1748558078.484 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:38.488Z,1748558078.488 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2025-05-29T22:34:38.488Z,1748558078.488 [DAT ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:38.488Z,1748558078.488 [DAT](INFO): Join timeout helper Thread ID is 1892
2025-05-29T22:34:38.700Z,1748558078.700 [DAT](INFO): Powering down
2025-05-29T22:34:38.769Z,1748558078.769 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:38.769Z,1748558078.769 [DAT](INFO): Powering down
2025-05-29T22:34:38.770Z,1748558078.770 [DAT ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:38.789Z,1748558078.789 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2025-05-29T22:34:38.790Z,1748558078.790 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:38.790Z,1748558078.790 [BackseatComponent](INFO): Join timeout helper Thread ID is 1893
2025-05-29T22:34:38.916Z,1748558078.916 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:38.916Z,1748558078.916 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:38.929Z,1748558078.929 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2025-05-29T22:34:38.929Z,1748558078.929 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:38.929Z,1748558078.929 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1894
2025-05-29T22:34:39.092Z,1748558079.092 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:39.092Z,1748558079.092 [WetLabsBB2FL](INFO): Powering down
2025-05-29T22:34:39.093Z,1748558079.093 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.113Z,1748558079.113 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2025-05-29T22:34:39.113Z,1748558079.113 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.113Z,1748558079.113 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1895
2025-05-29T22:34:39.444Z,1748558079.444 [CTD_Seabird](INFO): Powering down
2025-05-29T22:34:39.456Z,1748558079.456 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:39.456Z,1748558079.456 [CTD_Seabird](INFO): Powering down
2025-05-29T22:34:39.468Z,1748558079.468 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.481Z,1748558079.481 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2025-05-29T22:34:39.481Z,1748558079.481 [logger ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.481Z,1748558079.481 [logger](INFO): Join timeout helper Thread ID is 1896
2025-05-29T22:34:39.506Z,1748558079.506 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:39.506Z,1748558079.506 [logger ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.521Z,1748558079.521 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2025-05-29T22:34:39.521Z,1748558079.521 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.521Z,1748558079.521 [CommandLine](INFO): Join timeout helper Thread ID is 1897
2025-05-29T22:34:39.620Z,1748558079.620 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:39.621Z,1748558079.621 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.640Z,1748558079.640 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2025-05-29T22:34:39.641Z,1748558079.641 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.641Z,1748558079.641 [CommandExec](INFO): Join timeout helper Thread ID is 1898
2025-05-29T22:34:39.642Z,1748558079.642 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2025-05-29T22:34:39.642Z,1748558079.642 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:39.643Z,1748558079.643 [controlThread](INFO): Join timeout helper Thread ID is 1899
2025-05-29T22:34:39.744Z,1748558079.744 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2025-05-29T22:34:39.744Z,1748558079.744 [controlThread](DEBUG): Uninitializing ControlThread
2025-05-29T22:34:39.745Z,1748558079.745 [AHRS_M2](INFO): Powering down
2025-05-29T22:34:39.824Z,1748558079.824 [NAL9602](INFO): Powering down
2025-05-29T22:34:39.826Z,1748558079.826 [Sonardyne_Nano](INFO): Powering down
2025-05-29T22:34:40.028Z,1748558080.028 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2025-05-29T22:34:40.029Z,1748558080.029 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2025-05-29T22:34:40.029Z,1748558080.029 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2025-05-29T22:34:40.030Z,1748558080.030 [MissionManager](INFO): Uninitializing Mission Default
2025-05-29T22:34:40.030Z,1748558080.030 [Default] Stopped
2025-05-29T22:34:40.030Z,1748558080.030 [Default](DEBUG): Aggregate::uninitialize Default
2025-05-29T22:34:40.030Z,1748558080.030 [Default:B.GoToSurface] Stopped
2025-05-29T22:34:40.030Z,1748558080.030 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-05-29T22:34:40.030Z,1748558080.030 [Default:CheckIn] Stopped
2025-05-29T22:34:40.030Z,1748558080.030 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-29T22:34:40.030Z,1748558080.030 [Default:CheckIn:C.Wait] Stopped
2025-05-29T22:34:40.030Z,1748558080.030 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-29T22:34:40.034Z,1748558080.034 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2025-05-29T22:34:40.034Z,1748558080.034 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2025-05-29T22:34:40.034Z,1748558080.034 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2025-05-29T22:34:40.035Z,1748558080.035 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2025-05-29T22:34:40.035Z,1748558080.035 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-05-29T22:34:40.035Z,1748558080.035 [BuoyancyServo](INFO): Powering down
2025-05-29T22:34:40.048Z,1748558080.048 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-05-29T22:34:40.048Z,1748558080.048 [ElevatorServo](INFO): Powering down
2025-05-29T22:34:40.049Z,1748558080.049 [MassServo](DEBUG): Uninitialize Mass Servo.
2025-05-29T22:34:40.049Z,1748558080.049 [MassServo](INFO): Powering down
2025-05-29T22:34:40.050Z,1748558080.050 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2025-05-29T22:34:40.050Z,1748558080.050 [RudderServo](INFO): Powering down
2025-05-29T22:34:40.051Z,1748558080.051 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-05-29T22:34:40.051Z,1748558080.051 [ThrusterHE](INFO): Powering down
2025-05-29T22:34:40.052Z,1748558080.052 [SBIT](DEBUG): Uninitialize SBIT Component.
2025-05-29T22:34:40.052Z,1748558080.052 [IBIT](DEBUG): Uninitialize IBIT Component.
2025-05-29T22:34:40.052Z,1748558080.052 [CBIT](DEBUG): Uninitialize CBIT Component.
2025-05-29T22:34:40.053Z,1748558080.053 [CBIT](DEBUG): Powering off loads.
2025-05-29T22:34:40.064Z,1748558080.064 [CBIT](DEBUG): Disabling WDT.
2025-05-29T22:34:40.076Z,1748558080.076 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-05-29T22:34:40.076Z,1748558080.076 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-05-29T22:34:40.077Z,1748558080.077 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.102Z,1748558080.102 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-05-29T22:34:40.102Z,1748558080.102 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-05-29T22:34:40.118Z,1748558080.118 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.125Z,1748558080.125 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.157Z,1748558080.157 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.161Z,1748558080.161 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.167Z,1748558080.167 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.173Z,1748558080.173 [DAT ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.216Z,1748558080.216 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.270Z,1748558080.270 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-05-29T22:34:40.343Z,1748558080.343 [logger ThreadHandler](INFO): Thread cancelled.