2025-12-15T16:34:15.861Z,1765816455.861 [Supervisor](DEBUG): Initializing supervisor. 2025-12-15T16:34:15.865Z,1765816455.865 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-12-15T16:34:15.866Z,1765816455.866 [SyncHandler](INFO): Protected caller Thread ID is 837 2025-12-15T16:34:15.866Z,1765816455.866 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-12-15T16:34:15.867Z,1765816455.867 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-12-15T16:34:15.867Z,1765816455.867 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838 2025-12-15T16:34:15.871Z,1765816455.871 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-12-15T16:34:15.890Z,1765816455.890 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-12-15T16:34:15.891Z,1765816455.891 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-12-15T16:34:15.892Z,1765816455.892 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839 2025-12-15T16:34:15.896Z,1765816455.896 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-12-15T16:34:15.897Z,1765816455.897 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-12-15T16:34:15.897Z,1765816455.897 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840 2025-12-15T16:34:15.899Z,1765816455.899 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-12-15T16:34:15.900Z,1765816455.900 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-12-15T16:34:15.900Z,1765816455.900 [logger ThreadHandler](INFO): Protected caller Thread ID is 841 2025-12-15T16:34:15.904Z,1765816455.904 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-12-15T16:34:15.904Z,1765816455.904 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-12-15T16:34:15.909Z,1765816455.909 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-12-15T16:34:16.167Z,1765816456.167 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-12-15T16:34:16.169Z,1765816456.169 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-12-15T16:34:16.267Z,1765816456.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-12-15T16:34:16.268Z,1765816456.268 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-12-15T16:34:16.771Z,1765816456.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-12-15T16:34:16.773Z,1765816456.773 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-12-15T16:34:17.104Z,1765816457.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-12-15T16:34:17.106Z,1765816457.106 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-12-15T16:34:17.211Z,1765816457.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-12-15T16:34:17.212Z,1765816457.212 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-12-15T16:34:17.623Z,1765816457.623 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-12-15T16:34:17.625Z,1765816457.625 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-12-15T16:34:17.858Z,1765816457.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-12-15T16:34:17.860Z,1765816457.860 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-12-15T16:34:18.388Z,1765816458.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-12-15T16:34:18.390Z,1765816458.390 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-12-15T16:34:18.537Z,1765816458.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-12-15T16:34:19.028Z,1765816459.028 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-12-15T16:34:19.303Z,1765816459.303 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-12-15T16:34:20.119Z,1765816460.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-12-15T16:34:20.120Z,1765816460.120 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-12-15T16:34:20.503Z,1765816460.503 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-12-15T16:34:20.504Z,1765816460.504 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-12-15T16:34:20.688Z,1765816460.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-12-15T16:34:20.690Z,1765816460.690 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-12-15T16:34:20.811Z,1765816460.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-12-15T16:34:20.812Z,1765816460.812 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-12-15T16:34:21.039Z,1765816461.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-12-15T16:34:21.041Z,1765816461.041 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-12-15T16:34:21.298Z,1765816461.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-12-15T16:34:21.300Z,1765816461.300 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2025-12-15T16:34:21.303Z,1765816461.303 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2025-12-15T16:34:21.398Z,1765816461.398 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2025-12-15T16:34:21.507Z,1765816461.507 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2025-12-15T16:34:21.598Z,1765816461.598 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2025-12-15T16:34:21.707Z,1765816461.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2025-12-15T16:34:21.808Z,1765816461.808 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2025-12-15T16:34:21.930Z,1765816461.930 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2025-12-15T16:34:22.085Z,1765816462.085 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2025-12-15T16:34:22.237Z,1765816462.237 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2025-12-15T16:34:22.354Z,1765816462.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2025-12-15T16:34:22.624Z,1765816462.624 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-12-15T16:34:22.624Z,1765816462.624 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-12-15T16:34:22.636Z,1765816462.636 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-12-15T16:34:22.707Z,1765816462.707 [VerticalControl](DEBUG): Construct VerticalControl. 2025-12-15T16:34:22.767Z,1765816462.767 [VerticalControl] Loaded 2025-12-15T16:34:22.767Z,1765816462.767 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-12-15T16:34:22.770Z,1765816462.770 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-12-15T16:34:22.818Z,1765816462.818 [HorizontalControl] Loaded 2025-12-15T16:34:22.818Z,1765816462.818 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-12-15T16:34:22.820Z,1765816462.820 [SpeedControl](DEBUG): Construct SpeedControl. 2025-12-15T16:34:22.823Z,1765816462.823 [SpeedControl] Loaded 2025-12-15T16:34:22.823Z,1765816462.823 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-12-15T16:34:22.826Z,1765816462.826 [LoopControl](DEBUG): Construct LoopControl. 2025-12-15T16:34:22.827Z,1765816462.827 [LoopControl] Loaded 2025-12-15T16:34:22.827Z,1765816462.827 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-12-15T16:34:22.827Z,1765816462.827 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-12-15T16:34:22.829Z,1765816462.829 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-12-15T16:34:22.845Z,1765816462.845 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-12-15T16:34:22.845Z,1765816462.845 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-12-15T16:34:23.057Z,1765816463.057 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-12-15T16:34:23.058Z,1765816463.058 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-12-15T16:34:23.243Z,1765816463.243 [BuoyancyServo] Loaded 2025-12-15T16:34:23.243Z,1765816463.243 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-12-15T16:34:23.265Z,1765816463.265 [ElevatorServo] Loaded 2025-12-15T16:34:23.266Z,1765816463.266 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-12-15T16:34:23.286Z,1765816463.286 [MassServo] Loaded 2025-12-15T16:34:23.287Z,1765816463.287 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-12-15T16:34:23.307Z,1765816463.307 [RudderServo] Loaded 2025-12-15T16:34:23.308Z,1765816463.308 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-12-15T16:34:23.324Z,1765816463.324 [ThrusterHE] Loaded 2025-12-15T16:34:23.324Z,1765816463.324 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-12-15T16:34:23.325Z,1765816463.325 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-12-15T16:34:23.325Z,1765816463.325 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-12-15T16:34:23.462Z,1765816463.462 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-12-15T16:34:23.462Z,1765816463.462 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-12-15T16:34:23.476Z,1765816463.476 [NavChart] Loaded 2025-12-15T16:34:23.476Z,1765816463.476 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-12-15T16:34:23.482Z,1765816463.482 [UniversalFixResidualReporter] Loaded 2025-12-15T16:34:23.482Z,1765816463.482 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-12-15T16:34:23.482Z,1765816463.482 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-12-15T16:34:23.484Z,1765816463.484 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-12-15T16:34:23.571Z,1765816463.571 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-12-15T16:34:23.571Z,1765816463.571 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-12-15T16:34:24.381Z,1765816464.381 [AHRS_M2] Loaded 2025-12-15T16:34:24.381Z,1765816464.381 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-12-15T16:34:25.710Z,1765816465.710 [BPC1] Loaded 2025-12-15T16:34:25.710Z,1765816465.710 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-12-15T16:34:25.809Z,1765816465.809 [DAT] Loaded 2025-12-15T16:34:25.809Z,1765816465.809 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-12-15T16:34:25.810Z,1765816465.810 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4094D4E0 2025-12-15T16:34:25.811Z,1765816465.811 [DAT ThreadHandler](INFO): Protected caller Thread ID is 920 2025-12-15T16:34:25.954Z,1765816465.954 [DataOverHttps] Loaded 2025-12-15T16:34:25.954Z,1765816465.954 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-12-15T16:34:25.955Z,1765816465.955 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097D4E0 2025-12-15T16:34:25.955Z,1765816465.955 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 921 2025-12-15T16:34:25.978Z,1765816465.978 [Depth_Keller] Loaded 2025-12-15T16:34:25.979Z,1765816465.979 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-12-15T16:34:25.984Z,1765816465.984 [DropWeight] Loaded 2025-12-15T16:34:25.984Z,1765816465.984 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-12-15T16:34:26.046Z,1765816466.046 [NAL9602] Loaded 2025-12-15T16:34:26.047Z,1765816466.047 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-12-15T16:34:26.076Z,1765816466.076 [Onboard] Loaded 2025-12-15T16:34:26.076Z,1765816466.076 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-12-15T16:34:26.077Z,1765816466.077 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AD4E0 2025-12-15T16:34:26.078Z,1765816466.078 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922 2025-12-15T16:34:26.091Z,1765816466.091 [Power24vConverter] Loaded 2025-12-15T16:34:26.092Z,1765816466.092 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-12-15T16:34:26.107Z,1765816466.107 [Radio_Surface] Loaded 2025-12-15T16:34:26.107Z,1765816466.107 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-12-15T16:34:26.108Z,1765816466.108 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DD4E0 2025-12-15T16:34:26.109Z,1765816466.109 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923 2025-12-15T16:34:26.124Z,1765816466.124 [Sonardyne_Nano] Loaded 2025-12-15T16:34:26.124Z,1765816466.124 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-12-15T16:34:26.125Z,1765816466.125 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-12-15T16:34:26.126Z,1765816466.126 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-12-15T16:34:26.196Z,1765816466.196 [DepthRateCalculator] Loaded 2025-12-15T16:34:26.196Z,1765816466.196 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-12-15T16:34:26.201Z,1765816466.201 [PitchRateCalculator] Loaded 2025-12-15T16:34:26.201Z,1765816466.201 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-12-15T16:34:26.210Z,1765816466.210 [SpeedCalculator] Loaded 2025-12-15T16:34:26.210Z,1765816466.210 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-12-15T16:34:26.215Z,1765816466.215 [YawRateCalculator] Loaded 2025-12-15T16:34:26.215Z,1765816466.215 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-12-15T16:34:26.234Z,1765816466.234 [ElevatorOffsetCalculator] Loaded 2025-12-15T16:34:26.234Z,1765816466.234 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-12-15T16:34:26.235Z,1765816466.235 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-12-15T16:34:26.235Z,1765816466.235 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-12-15T16:34:26.416Z,1765816466.416 [CANONSampler] Loaded 2025-12-15T16:34:26.417Z,1765816466.417 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2025-12-15T16:34:26.478Z,1765816466.478 [CTD_Seabird] Loaded 2025-12-15T16:34:26.478Z,1765816466.478 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-12-15T16:34:26.480Z,1765816466.480 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A9B4E0 2025-12-15T16:34:26.480Z,1765816466.480 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 924 2025-12-15T16:34:26.502Z,1765816466.502 [PAR_Licor] Loaded 2025-12-15T16:34:26.502Z,1765816466.502 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-12-15T16:34:26.546Z,1765816466.546 [WetLabsBB2FL] Loaded 2025-12-15T16:34:26.547Z,1765816466.547 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-12-15T16:34:26.548Z,1765816466.548 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40ACB4E0 2025-12-15T16:34:26.548Z,1765816466.548 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 925 2025-12-15T16:34:26.549Z,1765816466.549 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-12-15T16:34:26.549Z,1765816466.549 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-12-15T16:34:26.597Z,1765816466.597 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-12-15T16:34:26.597Z,1765816466.597 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-12-15T16:34:26.995Z,1765816466.995 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-12-15T16:34:26.996Z,1765816466.996 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-12-15T16:34:27.232Z,1765816467.232 [SBIT](DEBUG): Construct Startup Built In Test. 2025-12-15T16:34:27.241Z,1765816467.241 [SBIT] Loaded 2025-12-15T16:34:27.241Z,1765816467.241 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-12-15T16:34:27.244Z,1765816467.244 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-12-15T16:34:27.257Z,1765816467.257 [IBIT] Loaded 2025-12-15T16:34:27.257Z,1765816467.257 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-12-15T16:34:27.262Z,1765816467.262 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-12-15T16:34:27.342Z,1765816467.342 [CBIT] Loaded 2025-12-15T16:34:27.342Z,1765816467.342 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-12-15T16:34:27.375Z,1765816467.375 [GFScanner] Loaded 2025-12-15T16:34:27.375Z,1765816467.375 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-12-15T16:34:27.375Z,1765816467.375 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-12-15T16:34:27.376Z,1765816467.376 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-12-15T16:34:27.542Z,1765816467.542 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-12-15T16:34:27.548Z,1765816467.548 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-12-15T16:34:27.551Z,1765816467.551 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-12-15T16:34:27.562Z,1765816467.562 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-12-15T16:34:27.563Z,1765816467.563 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C3D4E0 2025-12-15T16:34:27.563Z,1765816467.563 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 927 2025-12-15T16:34:27.568Z,1765816467.568 [Supervisor](INFO): Main Thread ID is 830 2025-12-15T16:34:27.568Z,1765816467.568 [Supervisor](DEBUG): Running supervisor. 2025-12-15T16:34:27.569Z,1765816467.569 [CommandExec ThreadHandler](INFO): Handler Thread ID is 928 2025-12-15T16:34:27.569Z,1765816467.569 [CommandExec](INFO): Initializing the command executive. 2025-12-15T16:34:27.571Z,1765816467.571 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929 2025-12-15T16:34:27.573Z,1765816467.573 [controlThread ThreadHandler](INFO): Handler Thread ID is 930 2025-12-15T16:34:27.573Z,1765816467.573 [controlThread](DEBUG): Initializing ControlThread 2025-12-15T16:34:27.574Z,1765816467.574 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-12-15T16:34:27.576Z,1765816467.576 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-12-15T16:34:27.577Z,1765816467.577 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-12-15T16:34:27.577Z,1765816467.577 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-12-15T16:34:27.579Z,1765816467.579 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-12-15T16:34:27.579Z,1765816467.579 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-12-15T16:34:27.582Z,1765816467.582 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-12-15T16:34:27.583Z,1765816467.583 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-12-15T16:34:27.583Z,1765816467.583 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-12-15T16:34:27.583Z,1765816467.583 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-12-15T16:34:27.584Z,1765816467.584 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-12-15T16:34:27.588Z,1765816467.588 [SBIT](INFO): Initialize SBIT Component. 2025-12-15T16:34:27.588Z,1765816467.588 [SBIT](IMPORTANT): git: 2025-12-11 2025-12-15T16:34:27.589Z,1765816467.589 [SBIT](INFO): git hash: c6c837cd550bef1cdcd0ab398e63035052ae6845 2025-12-15T16:34:27.589Z,1765816467.589 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-12-15T16:34:27.590Z,1765816467.590 [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-12-15T16:34:27.591Z,1765816467.591 [SBIT](INFO): Beginning SBIT in 85.000000 seconds. 2025-12-15T16:34:27.592Z,1765816467.592 [IBIT](INFO): Initialize IBIT Component. 2025-12-15T16:34:27.593Z,1765816467.593 [CBIT](DEBUG): Initialize CBIT Component. 2025-12-15T16:34:27.594Z,1765816467.594 [logger ThreadHandler](INFO): Handler Thread ID is 931 2025-12-15T16:34:27.604Z,1765816467.604 [CBIT](DEBUG): Initialized mux pins. 2025-12-15T16:34:27.604Z,1765816467.604 [CBIT](DEBUG): Initializing the watchdog timer. 2025-12-15T16:34:27.612Z,1765816467.612 [DAT ThreadHandler](INFO): Handler Thread ID is 932 2025-12-15T16:34:27.613Z,1765816467.613 [DAT](INFO): Powering up 2025-12-15T16:34:27.613Z,1765816467.613 [DAT](DEBUG): Initializing DAT. 2025-12-15T16:34:27.617Z,1765816467.617 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 934 2025-12-15T16:34:27.619Z,1765816467.619 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-12-15T16:34:27.628Z,1765816467.628 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-12-15T16:34:27.628Z,1765816467.628 [CBIT](DEBUG): Initializing heartbeat. 2025-12-15T16:34:27.629Z,1765816467.629 [Onboard ThreadHandler](INFO): Handler Thread ID is 935 2025-12-15T16:34:27.652Z,1765816467.652 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 936 2025-12-15T16:34:27.664Z,1765816467.664 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 937 2025-12-15T16:34:27.665Z,1765816467.665 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-12-15T16:34:27.669Z,1765816467.669 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 939 2025-12-15T16:34:27.673Z,1765816467.673 [WetLabsBB2FL](INFO): Powering up 2025-12-15T16:34:27.674Z,1765816467.674 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 941 2025-12-15T16:34:27.683Z,1765816467.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-12-15T16:34:27.684Z,1765816467.684 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-12-15T16:34:27.684Z,1765816467.684 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-12-15T16:34:27.684Z,1765816467.684 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-12-15T16:34:27.684Z,1765816467.684 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-12-15T16:34:27.684Z,1765816467.684 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-12-15T16:34:27.685Z,1765816467.685 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-12-15T16:34:27.685Z,1765816467.685 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-12-15T16:34:27.700Z,1765816467.700 [CBIT](DEBUG): Deactivating emergency mode. 2025-12-15T16:34:27.740Z,1765816467.740 [CBIT](DEBUG): Backplane powered. 2025-12-15T16:34:27.740Z,1765816467.740 [GFScanner](DEBUG): Initializing GFScanner 2025-12-15T16:34:27.740Z,1765816467.740 [GFScanner](DEBUG): Deactivating GF circuits. 2025-12-15T16:34:27.745Z,1765816467.745 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-12-15T16:34:27.746Z,1765816467.746 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-12-15T16:34:27.746Z,1765816467.746 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-12-15T16:34:27.751Z,1765816467.751 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-12-15T16:34:27.807Z,1765816467.807 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-12-15T16:34:27.831Z,1765816467.831 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-12-15T16:34:27.882Z,1765816467.882 [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-12-15T16:34:27.883Z,1765816467.883 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-12-15T16:34:27.883Z,1765816467.883 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-12-15T16:34:27.885Z,1765816467.885 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-12-15T16:34:28.056Z,1765816468.056 [Radio_Surface](INFO): Powering up 2025-12-15T16:34:28.173Z,1765816468.173 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2025-12-15T16:34:28.179Z,1765816468.179 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-12-15T16:34:28.193Z,1765816468.193 [Default:A.Wait](DEBUG): Construct Wait. 2025-12-15T16:34:28.195Z,1765816468.195 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-12-15T16:34:28.237Z,1765816468.237 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-12-15T16:34:28.239Z,1765816468.239 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-12-15T16:34:28.281Z,1765816468.281 [Default:E.Execute](DEBUG): Construct Execute. 2025-12-15T16:34:28.284Z,1765816468.284 [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-12-15T16:34:28.297Z,1765816468.297 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,Reporter,LogSplitter, 2025-12-15T16:34:28.304Z,1765816468.304 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-12-15T16:34:28.456Z,1765816468.456 [Depth_Keller](INFO): Initializing. 2025-12-15T16:34:28.458Z,1765816468.458 [Power24vConverter](INFO): Powering up. 2025-12-15T16:34:28.458Z,1765816468.458 [Sonardyne_Nano](INFO): Initializing. 2025-12-15T16:34:28.476Z,1765816468.476 [CANONSampler](INFO): Powering down 2025-12-15T16:34:28.500Z,1765816468.500 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-12-15T16:34:28.526Z,1765816468.526 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-12-15T16:34:28.532Z,1765816468.532 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-12-15T16:34:28.533Z,1765816468.533 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-12-15T16:34:28.540Z,1765816468.540 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-12-15T16:34:28.541Z,1765816468.541 [MassServo](DEBUG): Initializing EZServoServo. 2025-12-15T16:34:28.548Z,1765816468.548 [MassServo](DEBUG): Initializing MassServo. 2025-12-15T16:34:28.549Z,1765816468.549 [RudderServo](DEBUG): Initializing EZServoServo. 2025-12-15T16:34:28.556Z,1765816468.556 [RudderServo](DEBUG): Initializing RudderServo. 2025-12-15T16:34:28.557Z,1765816468.557 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-12-15T16:34:28.564Z,1765816468.564 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-12-15T16:34:28.737Z,1765816468.737 [Depth_Keller](ERROR): Pressure or depth reading out of range: 915.616455 decibar, 0.000000 m 2025-12-15T16:34:28.749Z,1765816468.749 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-12-15T16:34:29.780Z,1765816469.780 [WetLabsBB2FL](INFO): Powering down 2025-12-15T16:34:30.730Z,1765816470.730 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-12-15T16:34:31.972Z,1765816471.972 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2025-12-15T16:34:34.193Z,1765816474.193 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-12-15T16:34:39.233Z,1765816479.233 [DAT](INFO): DAT read: 2025-12-15T16:34:39.234Z,1765816479.234 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-12-15T16:34:40.748Z,1765816480.748 [DAT](INFO): DAT read: MF Frequency Band 2025-12-15T16:34:40.752Z,1765816480.752 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-12-15T16:34:40.753Z,1765816480.753 [DAT](INFO): DAT read: Dec 10 2025 23:12:09 2025-12-15T16:34:42.005Z,1765816482.005 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-12-15T16:34:42.006Z,1765816482.006 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-12-15T16:34:42.006Z,1765816482.006 [DAT](INFO): commRate: 1200 2025-12-15T16:34:44.076Z,1765816484.076 [DAT](INFO): entering command mode 2025-12-15T16:34:44.272Z,1765816484.272 [DAT](INFO): DAT read: 2025-12-15T16:34:44.273Z,1765816484.273 [DAT](INFO): DAT read: user:1> 2025-12-15T16:34:44.273Z,1765816484.273 [DAT](INFO): setting verbose to 3 2025-12-15T16:34:44.525Z,1765816484.525 [DAT](INFO): DAT read: user:1> 2025-12-15T16:34:44.526Z,1765816484.526 [DAT](INFO): DAT read: Verbose | 3 2025-12-15T16:34:44.527Z,1765816484.527 [DAT](INFO): set verbose to 3 2025-12-15T16:34:44.527Z,1765816484.527 [DAT](INFO): setting DatVerbose to 27440 2025-12-15T16:34:44.777Z,1765816484.777 [DAT](INFO): DAT read: user:2> 2025-12-15T16:34:44.777Z,1765816484.777 [DAT](INFO): DAT read: DatVerbose | 27440 2025-12-15T16:34:44.778Z,1765816484.778 [DAT](INFO): set DatVerbose to 27440 2025-12-15T16:34:44.778Z,1765816484.778 [DAT](INFO): setting transmit power to 8 2025-12-15T16:34:45.029Z,1765816485.029 [DAT](INFO): DAT read: user:3> 2025-12-15T16:34:45.029Z,1765816485.029 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-12-15T16:34:45.030Z,1765816485.030 [DAT](INFO): set transmit power to 8 2025-12-15T16:34:45.030Z,1765816485.030 [DAT](INFO): setting local address to 8 2025-12-15T16:34:45.280Z,1765816485.280 [DAT](INFO): DAT read: user:4> 2025-12-15T16:34:45.281Z,1765816485.281 [DAT](INFO): DAT read: LocalAddr | 8 2025-12-15T16:34:45.282Z,1765816485.282 [DAT](INFO): set local address to 8 2025-12-15T16:34:45.283Z,1765816485.283 [DAT](INFO): Setting time to: 16:34:45 And date to:12/15/2025 2025-12-15T16:34:45.533Z,1765816485.533 [DAT](INFO): DAT read: user:5> 2025-12-15T16:34:45.533Z,1765816485.533 [DAT](INFO): DAT read: Mon Dec 15, 2025 16:34:45 2025-12-15T16:34:45.534Z,1765816485.534 [DAT](INFO): Local DAT time set to Mon Dec 15, 2025 16:34:45 2025-12-15T16:34:56.185Z,1765816496.185 [NAL9602](INFO): Powering up NAL9602 2025-12-15T16:35:07.130Z,1765816507.130 [NAL9602](INFO): NAL9602 initialized 2025-12-15T16:35:33.354Z,1765816533.354 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T16:35:44.257Z,1765816544.257 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T16:35:48.701Z,1765816548.701 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:35:53.167Z,1765816553.167 [SBIT](IMPORTANT): Beginning Startup BIT 2025-12-15T16:35:53.172Z,1765816553.172 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-12-15T16:35:57.701Z,1765816557.701 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.003697 CHAN A1 (24V): 0.000728 CHAN A2 (12V): -0.001894 CHAN A3 (5V): -0.001889 CHAN B0 (3.3V): -0.000063 CHAN B1 (3.15aV): -0.000020 CHAN B2 (3.15bV): -0.000026 CHAN B3 (GND): 0.000029 OPEN: -0.000495 Full Scale: +/- 1 mA 2025-12-15T16:36:02.437Z,1765816562.437 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:36:16.577Z,1765816576.577 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:36:30.717Z,1765816590.717 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:36:44.469Z,1765816604.469 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:36:46.935Z,1765816606.935 [SBIT](IMPORTANT): SBIT PASSED 2025-12-15T16:36:46.935Z,1765816606.935 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-12-15T16:36:46.944Z,1765816606.944 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=11 count; 2025-12-15T16:36:46.944Z,1765816606.944 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter; 2025-12-15T16:36:46.944Z,1765816606.944 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter; 2025-12-15T16:36:46.945Z,1765816606.945 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=126.523148 cubic_centimeter; 2025-12-15T16:36:46.945Z,1765816606.945 [SBIT](IMPORTANT): VerticalControl.massDefault=16.489347 millimeter; 2025-12-15T16:36:47.310Z,1765816607.310 [MissionManager](IMPORTANT): Started mission Startup 2025-12-15T16:36:47.311Z,1765816607.311 [Startup] Running Loop=1 2025-12-15T16:36:47.311Z,1765816607.311 [Startup](DEBUG): Aggregate::initialize Startup 2025-12-15T16:36:47.311Z,1765816607.311 [Startup:A.GoToSurface] Running Loop=1 2025-12-15T16:36:47.311Z,1765816607.311 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-12-15T16:36:47.313Z,1765816607.313 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-12-15T16:36:47.313Z,1765816607.313 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-12-15T16:36:47.314Z,1765816607.314 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-12-15T16:36:47.314Z,1765816607.314 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-12-15T16:36:47.314Z,1765816607.314 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-12-15T16:36:47.315Z,1765816607.315 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-12-15T16:36:47.316Z,1765816607.316 [Startup:StartupSatComms] Running Loop=1 2025-12-15T16:36:47.316Z,1765816607.316 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-12-15T16:36:47.316Z,1765816607.316 [Startup:StartupSatComms:A] Running Loop=1 2025-12-15T16:36:47.715Z,1765816607.715 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-12-15T16:36:54.438Z,1765816614.438 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004746 2025-12-15T16:36:59.140Z,1765816619.140 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:37:13.279Z,1765816633.279 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:37:27.419Z,1765816647.419 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:37:27.851Z,1765816647.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-12-15T16:37:27.851Z,1765816647.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:37:27.861Z,1765816647.861 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:37:28.257Z,1765816648.257 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:37:28.257Z,1765816648.257 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-12-15T16:37:41.155Z,1765816661.155 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:37:47.641Z,1765816667.641 [Startup:StartupSatComms:A](INFO): Timed out from 2025-12-15T16:36:47.3Z 2025-12-15T16:37:47.641Z,1765816667.641 [Startup:StartupSatComms:A] Stopped 2025-12-15T16:37:47.641Z,1765816667.641 [Startup:StartupSatComms:B] Running Loop=1 2025-12-15T16:37:48.041Z,1765816668.041 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-12-15T16:37:54.894Z,1765816674.894 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251215T163415/Courier0000.lzma 2025-12-15T16:37:54.897Z,1765816674.897 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T16:37:55.896Z,1765816675.896 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0000.lzma.bak 2025-12-15T16:37:55.896Z,1765816675.896 [DataOverHttps](INFO): SBD MOMSN=26497268 2025-12-15T16:38:12.844Z,1765816692.844 [DataOverHttps](INFO): Sending 826 bytes from file Logs/20251215T163415/Express0001.lzma 2025-12-15T16:38:13.844Z,1765816693.844 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0001.lzma.bak 2025-12-15T16:38:13.844Z,1765816693.844 [DataOverHttps](INFO): SBD MOMSN=26497271 2025-12-15T16:38:14.199Z,1765816694.199 [CommandExec](IMPORTANT): got command failComponent 2025-12-15T16:38:14.199Z,1765816694.199 [CommandExec](IMPORTANT): Failed components: 2025-12-15T16:38:14.199Z,1765816694.199 [CommandExec](IMPORTANT): No failed Components. 2025-12-15T16:38:15.120Z,1765816695.120 [Startup:StartupSatComms:B] Stopped 2025-12-15T16:38:15.120Z,1765816695.120 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-12-15T16:38:15.120Z,1765816695.120 [Startup:StartupSatComms] Stopped 2025-12-15T16:38:15.120Z,1765816695.120 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-12-15T16:38:15.121Z,1765816695.121 [Startup](INFO): Completed Startup 2025-12-15T16:38:15.121Z,1765816695.121 [MissionManager](INFO): Startup is completed. 2025-12-15T16:38:15.121Z,1765816695.121 [MissionManager](INFO): Uninitializing Mission Startup 2025-12-15T16:38:15.121Z,1765816695.121 [Startup] Stopped 2025-12-15T16:38:15.122Z,1765816695.122 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-12-15T16:38:15.122Z,1765816695.122 [Startup:A.GoToSurface] Stopped 2025-12-15T16:38:15.122Z,1765816695.122 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-12-15T16:38:15.524Z,1765816695.524 [MissionManager](IMPORTANT): Started mission Default 2025-12-15T16:38:15.524Z,1765816695.524 [Default] Running Loop=1 2025-12-15T16:38:15.525Z,1765816695.525 [Default](DEBUG): Aggregate::initialize Default 2025-12-15T16:38:15.525Z,1765816695.525 [Default:B.GoToSurface] Running Loop=1 2025-12-15T16:38:15.525Z,1765816695.525 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-12-15T16:38:15.525Z,1765816695.525 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-12-15T16:38:15.525Z,1765816695.525 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-12-15T16:38:15.526Z,1765816695.526 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-12-15T16:38:15.526Z,1765816695.526 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-12-15T16:38:15.526Z,1765816695.526 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-12-15T16:38:15.527Z,1765816695.527 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-12-15T16:38:15.527Z,1765816695.527 [Default:A.Wait] Running Loop=1 2025-12-15T16:38:15.527Z,1765816695.527 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-12-15T16:38:16.279Z,1765816696.279 [CommandExec](IMPORTANT): got command gfscan 2025-12-15T16:38:16.369Z,1765816696.369 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-12-15T16:38:19.815Z,1765816699.815 [CommandExec](IMPORTANT): got command strobe off 2025-12-15T16:38:19.816Z,1765816699.816 [CommandExec](IMPORTANT): Deactivating strobe 2025-12-15T16:38:20.801Z,1765816700.801 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002325 CHAN A1 (24V): 0.000818 CHAN A2 (12V): -0.002391 CHAN A3 (5V): -0.001536 CHAN B0 (3.3V): -0.000001 CHAN B1 (3.15aV): -0.000111 CHAN B2 (3.15bV): -0.000113 CHAN B3 (GND): 0.000182 OPEN: -0.000507 Full Scale: +/- 1 mA 2025-12-15T16:38:21.564Z,1765816701.564 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:38:28.860Z,1765816708.860 [Default:A.Wait](INFO): Done Waiting. 2025-12-15T16:38:28.860Z,1765816708.860 [Default:A.Wait] Stopped 2025-12-15T16:38:28.860Z,1765816708.860 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T16:38:29.256Z,1765816709.256 [Default:CheckIn] Running Loop=1 2025-12-15T16:38:29.256Z,1765816709.256 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T16:38:29.256Z,1765816709.256 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T16:38:29.660Z,1765816709.660 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-12-15T16:38:34.087Z,1765816714.087 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:38:47.419Z,1765816727.419 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:38:59.943Z,1765816739.943 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:39:12.874Z,1765816752.874 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:39:25.799Z,1765816765.799 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:39:30.653Z,1765816770.653 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-12-15T16:39:38.327Z,1765816778.327 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:39:50.847Z,1765816790.847 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:40:04.583Z,1765816804.583 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:40:09.849Z,1765816809.849 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-12-15T16:40:17.923Z,1765816817.923 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:40:28.867Z,1765816828.867 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-12-15T16:40:28.867Z,1765816828.867 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:40:28.878Z,1765816828.878 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:40:29.280Z,1765816829.280 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:40:29.281Z,1765816829.281 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-12-15T16:40:30.851Z,1765816830.851 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T16:40:43.383Z,1765816843.383 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5. 2025-12-15T16:40:43.387Z,1765816843.387 [BPC1](INFO): Received data from all battery sticks. 2025-12-15T16:41:10.994Z,1765816870.994 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent 2025-12-15T16:41:11.007Z,1765816871.007 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 27.000002 % 2025-12-15T16:43:29.521Z,1765817009.521 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-12-15T16:38:29.3Z 2025-12-15T16:43:29.521Z,1765817009.521 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T16:43:29.521Z,1765817009.521 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T16:43:29.844Z,1765817009.844 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-12-15T16:43:29.844Z,1765817009.844 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:43:29.846Z,1765817009.846 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-12-15T16:43:29.855Z,1765817009.855 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:43:30.266Z,1765817010.266 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:43:30.267Z,1765817010.267 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-12-15T16:43:37.110Z,1765817017.110 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20251215T163415/Courier0004.lzma 2025-12-15T16:43:38.112Z,1765817018.112 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0004.lzma.bak 2025-12-15T16:43:38.112Z,1765817018.112 [DataOverHttps](INFO): SBD MOMSN=26497500 2025-12-15T16:43:53.706Z,1765817033.706 [DataOverHttps](INFO): Sending 505 bytes from file Logs/20251215T163415/Express0005.lzma 2025-12-15T16:43:54.708Z,1765817034.708 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0005.lzma.bak 2025-12-15T16:43:54.708Z,1765817034.708 [DataOverHttps](INFO): SBD MOMSN=26497502 2025-12-15T16:43:55.722Z,1765817035.722 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T16:43:55.722Z,1765817035.722 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T16:43:55.722Z,1765817035.722 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T16:44:30.395Z,1765817070.395 [CommandExec](IMPORTANT): got command burn on 2025-12-15T16:44:30.395Z,1765817070.395 [CommandExec](IMPORTANT): Activating dropweight wire 2025-12-15T16:44:35.507Z,1765817075.507 [CommandExec](IMPORTANT): got command burn off 2025-12-15T16:44:35.507Z,1765817075.507 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-12-15T16:45:08.020Z,1765817108.020 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-12-15T16:45:08.020Z,1765817108.020 [NAL9602] Data Fault, FailCount= 1 2025-12-15T16:45:08.020Z,1765817108.020 [NAL9602](ERROR): Data Fault 2025-12-15T16:45:08.037Z,1765817108.037 [CBIT](ERROR): Data Fault in component: NAL9602 2025-12-15T16:45:08.426Z,1765817108.426 [NAL9602](INFO): Powering down 2025-12-15T16:45:09.244Z,1765817109.244 [CBIT](INFO): Clearing failed state for component NAL9602 2025-12-15T16:45:09.245Z,1765817109.245 [NAL9602] No Fault, FailCount= 1 2025-12-15T16:45:38.740Z,1765817138.740 [NAL9602](INFO): Powering up NAL9602 2025-12-15T16:45:49.636Z,1765817149.636 [NAL9602](INFO): NAL9602 initialized 2025-12-15T16:46:30.855Z,1765817190.855 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-12-15T16:46:30.855Z,1765817190.855 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:46:30.870Z,1765817190.870 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:46:31.331Z,1765817191.331 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:46:31.331Z,1765817191.331 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-12-15T16:48:56.304Z,1765817336.304 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T16:48:56.304Z,1765817336.304 [Default:CheckIn:C.Wait] Stopped 2025-12-15T16:48:56.304Z,1765817336.304 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T16:48:56.305Z,1765817336.305 [Default:CheckIn:D] Running Loop=1 2025-12-15T16:48:56.693Z,1765817336.693 [Default:CheckIn:D] Stopped 2025-12-15T16:48:56.693Z,1765817336.693 [Default:CheckIn:E] Running Loop=1 2025-12-15T16:48:57.104Z,1765817337.104 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.686135 min 2025-12-15T16:48:57.104Z,1765817337.104 [Default:CheckIn:E] Stopped 2025-12-15T16:48:57.104Z,1765817337.104 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T16:48:57.104Z,1765817337.104 [Default:CheckIn] Stopped 2025-12-15T16:48:57.105Z,1765817337.105 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T16:48:57.105Z,1765817337.105 [Default:CheckIn](INFO): Running loop #2 2025-12-15T16:48:57.105Z,1765817337.105 [Default:CheckIn] Running Loop=2 2025-12-15T16:48:57.105Z,1765817337.105 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T16:48:57.105Z,1765817337.105 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T16:49:31.840Z,1765817371.840 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-12-15T16:49:31.840Z,1765817371.840 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:49:31.850Z,1765817371.850 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:49:32.277Z,1765817372.277 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:49:32.277Z,1765817372.277 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-12-15T16:52:32.851Z,1765817552.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-12-15T16:52:32.851Z,1765817552.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:52:32.885Z,1765817552.885 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:52:33.269Z,1765817553.269 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:52:33.269Z,1765817553.269 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-12-15T16:53:57.273Z,1765817637.273 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-12-15T16:48:57.1Z 2025-12-15T16:53:57.273Z,1765817637.273 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T16:53:57.273Z,1765817637.273 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T16:54:04.586Z,1765817644.586 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251215T163415/Courier0007.lzma 2025-12-15T16:54:05.588Z,1765817645.588 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0007.lzma.bak 2025-12-15T16:54:05.588Z,1765817645.588 [DataOverHttps](INFO): SBD MOMSN=26497559 2025-12-15T16:54:23.727Z,1765817663.727 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20251215T163415/Express0008.lzma 2025-12-15T16:54:24.728Z,1765817664.728 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0008.lzma.bak 2025-12-15T16:54:24.728Z,1765817664.728 [DataOverHttps](INFO): SBD MOMSN=26497561 2025-12-15T16:54:25.997Z,1765817665.997 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T16:54:25.997Z,1765817665.997 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T16:54:25.997Z,1765817665.997 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T16:55:33.863Z,1765817733.863 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2025-12-15T16:55:33.863Z,1765817733.863 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:55:33.873Z,1765817733.873 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:55:34.290Z,1765817734.290 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:55:34.290Z,1765817734.290 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2025-12-15T16:55:50.821Z,1765817750.821 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-12-15T16:55:50.822Z,1765817750.822 [NAL9602] Data Fault, FailCount= 2 2025-12-15T16:55:50.822Z,1765817750.822 [NAL9602](ERROR): Data Fault 2025-12-15T16:55:50.840Z,1765817750.840 [CBIT](ERROR): Data Fault in component: NAL9602 2025-12-15T16:55:51.228Z,1765817751.228 [NAL9602](INFO): Powering down 2025-12-15T16:55:52.072Z,1765817752.072 [CBIT](INFO): Clearing failed state for component NAL9602 2025-12-15T16:55:52.072Z,1765817752.072 [NAL9602] No Fault, FailCount= 2 2025-12-15T16:56:21.532Z,1765817781.532 [NAL9602](INFO): Powering up NAL9602 2025-12-15T16:56:32.437Z,1765817792.437 [NAL9602](INFO): NAL9602 initialized 2025-12-15T16:58:34.880Z,1765817914.880 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2025-12-15T16:58:34.880Z,1765817914.880 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T16:58:34.891Z,1765817914.891 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T16:58:35.286Z,1765817915.286 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T16:58:35.287Z,1765817915.287 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2025-12-15T16:59:26.600Z,1765817966.600 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T16:59:26.600Z,1765817966.600 [Default:CheckIn:C.Wait] Stopped 2025-12-15T16:59:26.600Z,1765817966.600 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T16:59:26.600Z,1765817966.600 [Default:CheckIn:D] Running Loop=1 2025-12-15T16:59:26.992Z,1765817966.992 [Default:CheckIn:D] Stopped 2025-12-15T16:59:26.993Z,1765817966.993 [Default:CheckIn:E] Running Loop=1 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.191132 min 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn:E] Stopped 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn] Stopped 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn](INFO): Running loop #3 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn] Running Loop=3 2025-12-15T16:59:27.379Z,1765817967.379 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T16:59:27.380Z,1765817967.380 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:01:35.882Z,1765818095.882 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2025-12-15T17:01:35.883Z,1765818095.883 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T17:01:35.901Z,1765818095.901 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T17:01:36.304Z,1765818096.304 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T17:01:36.304Z,1765818096.304 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2025-12-15T17:04:27.556Z,1765818267.556 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-12-15T16:59:27.4Z 2025-12-15T17:04:27.556Z,1765818267.556 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:04:27.556Z,1765818267.556 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:04:36.900Z,1765818276.900 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2025-12-15T17:04:36.900Z,1765818276.900 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T17:04:36.943Z,1765818276.943 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T17:04:36.998Z,1765818276.998 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251215T163415/Courier0010.lzma 2025-12-15T17:04:37.329Z,1765818277.329 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T17:04:37.329Z,1765818277.329 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2025-12-15T17:04:38.000Z,1765818278.000 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0010.lzma.bak 2025-12-15T17:04:38.000Z,1765818278.000 [DataOverHttps](INFO): SBD MOMSN=26497583 2025-12-15T17:04:53.590Z,1765818293.590 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251215T163415/Express0011.lzma 2025-12-15T17:04:54.592Z,1765818294.592 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0011.lzma.bak 2025-12-15T17:04:54.593Z,1765818294.593 [DataOverHttps](INFO): SBD MOMSN=26497585 2025-12-15T17:04:55.897Z,1765818295.897 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:04:55.897Z,1765818295.897 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:04:55.897Z,1765818295.897 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:06:33.255Z,1765818393.255 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-12-15T17:06:33.255Z,1765818393.255 [NAL9602] Data Fault, FailCount= 3 2025-12-15T17:06:33.255Z,1765818393.255 [NAL9602](ERROR): Data Fault 2025-12-15T17:06:33.272Z,1765818393.272 [CBIT](ERROR): Data Fault in component: NAL9602 2025-12-15T17:06:33.653Z,1765818393.653 [NAL9602](INFO): Powering down 2025-12-15T17:06:34.484Z,1765818394.484 [CBIT](INFO): Clearing failed state for component NAL9602 2025-12-15T17:06:34.484Z,1765818394.484 [NAL9602] No Fault, FailCount= 3 2025-12-15T17:07:03.960Z,1765818423.960 [NAL9602](INFO): Powering up NAL9602 2025-12-15T17:07:14.868Z,1765818434.868 [NAL9602](INFO): NAL9602 initialized 2025-12-15T17:07:37.904Z,1765818457.904 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2025-12-15T17:07:37.904Z,1765818457.904 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-12-15T17:07:37.914Z,1765818457.914 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-12-15T17:07:38.328Z,1765818458.328 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-12-15T17:07:38.328Z,1765818458.328 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2025-12-15T17:09:33.041Z,1765818573.041 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170931.00,A,3648.17319,N,12147.28611,W,0.292,321.07,151225,,,A*76 2025-12-15T17:09:33.044Z,1765818573.044 [NAL9602](INFO): GPS fix at 20251215T170931: (36.802886, -121.788102) 2025-12-15T17:09:56.494Z,1765818596.494 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:09:56.494Z,1765818596.494 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:09:56.494Z,1765818596.494 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:09:56.494Z,1765818596.494 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:09:56.890Z,1765818596.890 [Default:CheckIn:D] Stopped 2025-12-15T17:09:56.890Z,1765818596.890 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:09:57.299Z,1765818597.299 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.689429 min 2025-12-15T17:09:57.299Z,1765818597.299 [Default:CheckIn:E] Stopped 2025-12-15T17:09:57.299Z,1765818597.299 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:09:57.299Z,1765818597.299 [Default:CheckIn] Stopped 2025-12-15T17:09:57.299Z,1765818597.299 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:09:57.300Z,1765818597.300 [Default:CheckIn](INFO): Running loop #4 2025-12-15T17:09:57.300Z,1765818597.300 [Default:CheckIn] Running Loop=4 2025-12-15T17:09:57.300Z,1765818597.300 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:09:57.300Z,1765818597.300 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:09:59.307Z,1765818599.307 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170957.00,A,3648.16637,N,12147.28602,W,0.156,322.80,151225,,,A*7B 2025-12-15T17:09:59.309Z,1765818599.309 [NAL9602](INFO): GPS fix at 20251215T170957: (36.802773, -121.788100) 2025-12-15T17:09:59.320Z,1765818599.320 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:09:59.320Z,1765818599.320 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:10:06.150Z,1765818606.150 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20251215T163415/Courier0013.lzma 2025-12-15T17:10:07.152Z,1765818607.152 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0013.lzma.bak 2025-12-15T17:10:07.152Z,1765818607.152 [DataOverHttps](INFO): SBD MOMSN=26497591 2025-12-15T17:10:26.054Z,1765818626.054 [DataOverHttps](INFO): Sending 402 bytes from file Logs/20251215T163415/Express0014.lzma 2025-12-15T17:10:27.057Z,1765818627.057 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0014.lzma.bak 2025-12-15T17:10:27.057Z,1765818627.057 [DataOverHttps](INFO): SBD MOMSN=26497594 2025-12-15T17:10:28.077Z,1765818628.077 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:10:28.077Z,1765818628.077 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:10:28.077Z,1765818628.077 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:10:31.275Z,1765818631.275 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T17:15:28.633Z,1765818928.633 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:15:28.633Z,1765818928.633 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:15:28.633Z,1765818928.633 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:15:28.634Z,1765818928.634 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:15:29.043Z,1765818929.043 [Default:CheckIn:D] Stopped 2025-12-15T17:15:29.043Z,1765818929.043 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:15:29.448Z,1765818929.448 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.225301 min 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn:E] Stopped 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn] Stopped 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn](INFO): Running loop #5 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn] Running Loop=5 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:15:29.449Z,1765818929.449 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:15:31.449Z,1765818931.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171530.00,A,3648.15692,N,12147.27451,W,0.447,151.81,151225,,,A*72 2025-12-15T17:15:31.452Z,1765818931.452 [NAL9602](INFO): GPS fix at 20251215T171530: (36.802615, -121.787909) 2025-12-15T17:15:31.487Z,1765818931.487 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:15:31.487Z,1765818931.487 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:15:38.870Z,1765818938.870 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0016.lzma 2025-12-15T17:15:39.872Z,1765818939.872 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0016.lzma.bak 2025-12-15T17:15:39.872Z,1765818939.872 [DataOverHttps](INFO): SBD MOMSN=26497609 2025-12-15T17:15:49.633Z,1765818949.633 [NAL9602](INFO): SBD MO Status=0, MOMSN=65, MT Status=0, MTMSN=0 2025-12-15T17:15:49.633Z,1765818949.633 [NAL9602](INFO): No messages in MT queue 2025-12-15T17:15:55.742Z,1765818955.742 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251215T163415/Express0017.lzma 2025-12-15T17:15:56.744Z,1765818956.744 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0017.lzma.bak 2025-12-15T17:15:56.744Z,1765818956.744 [DataOverHttps](INFO): SBD MOMSN=26497612 2025-12-15T17:15:58.125Z,1765818958.125 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:15:58.125Z,1765818958.125 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:15:58.125Z,1765818958.125 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:16:20.333Z,1765818980.333 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T17:20:58.703Z,1765819258.703 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:20:58.703Z,1765819258.703 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:20:58.703Z,1765819258.703 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:20:58.704Z,1765819258.704 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:20:59.106Z,1765819259.106 [Default:CheckIn:D] Stopped 2025-12-15T17:20:59.106Z,1765819259.106 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:20:59.522Z,1765819259.522 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.726351 min 2025-12-15T17:20:59.522Z,1765819259.522 [Default:CheckIn:E] Stopped 2025-12-15T17:20:59.523Z,1765819259.523 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:20:59.523Z,1765819259.523 [Default:CheckIn] Stopped 2025-12-15T17:20:59.523Z,1765819259.523 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:20:59.523Z,1765819259.523 [Default:CheckIn](INFO): Running loop #6 2025-12-15T17:20:59.523Z,1765819259.523 [Default:CheckIn] Running Loop=6 2025-12-15T17:20:59.523Z,1765819259.523 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:20:59.523Z,1765819259.523 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:21:01.525Z,1765819261.525 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172100.00,A,3648.17252,N,12147.28037,W,0.253,152.26,151225,,,A*7A 2025-12-15T17:21:01.527Z,1765819261.527 [NAL9602](INFO): GPS fix at 20251215T172100: (36.802875, -121.788006) 2025-12-15T17:21:01.538Z,1765819261.538 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:21:01.538Z,1765819261.538 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:21:09.110Z,1765819269.110 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251215T163415/Courier0019.lzma 2025-12-15T17:21:10.112Z,1765819270.112 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0019.lzma.bak 2025-12-15T17:21:10.112Z,1765819270.112 [DataOverHttps](INFO): SBD MOMSN=26497616 2025-12-15T17:21:26.234Z,1765819286.234 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20251215T163415/Express0020.lzma 2025-12-15T17:21:27.236Z,1765819287.236 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0020.lzma.bak 2025-12-15T17:21:27.236Z,1765819287.236 [DataOverHttps](INFO): SBD MOMSN=26497619 2025-12-15T17:21:28.623Z,1765819288.623 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:21:28.623Z,1765819288.623 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:21:28.623Z,1765819288.623 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:23:56.452Z,1765819436.452 [NAL9602](INFO): SBD MO Status=2, MOMSN=66, MT Status=2, MTMSN=0 2025-12-15T17:23:56.452Z,1765819436.452 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:24:12.210Z,1765819452.210 [NAL9602](INFO): SBD MO Status=2, MOMSN=66, MT Status=2, MTMSN=0 2025-12-15T17:24:12.210Z,1765819452.210 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:24:58.668Z,1765819498.668 [NAL9602](INFO): SBD MO Status=2, MOMSN=66, MT Status=2, MTMSN=0 2025-12-15T17:24:58.668Z,1765819498.668 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:25:24.120Z,1765819524.120 [NAL9602](INFO): SBD MO Status=2, MOMSN=66, MT Status=2, MTMSN=0 2025-12-15T17:25:24.120Z,1765819524.120 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:25:40.684Z,1765819540.684 [NAL9602](INFO): SBD MO Status=2, MOMSN=66, MT Status=2, MTMSN=0 2025-12-15T17:25:40.684Z,1765819540.684 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:26:00.889Z,1765819560.889 [NAL9602](INFO): SBD MO Status=0, MOMSN=66, MT Status=0, MTMSN=0 2025-12-15T17:26:00.889Z,1765819560.889 [NAL9602](INFO): No messages in MT queue 2025-12-15T17:26:29.181Z,1765819589.181 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:26:29.181Z,1765819589.181 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:26:29.181Z,1765819589.181 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:26:29.181Z,1765819589.181 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:26:29.581Z,1765819589.581 [Default:CheckIn:D] Stopped 2025-12-15T17:26:29.581Z,1765819589.581 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:26:29.985Z,1765819589.985 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.234281 min 2025-12-15T17:26:29.986Z,1765819589.986 [Default:CheckIn:E] Stopped 2025-12-15T17:26:29.986Z,1765819589.986 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:26:29.986Z,1765819589.986 [Default:CheckIn] Stopped 2025-12-15T17:26:29.986Z,1765819589.986 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:26:29.986Z,1765819589.986 [Default:CheckIn](INFO): Running loop #7 2025-12-15T17:26:29.986Z,1765819589.986 [Default:CheckIn] Running Loop=7 2025-12-15T17:26:29.986Z,1765819589.986 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:26:29.987Z,1765819589.987 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:26:31.997Z,1765819591.997 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172631.00,A,3648.16811,N,12147.27552,W,0.583,152.26,151225,,,A*70 2025-12-15T17:26:31.999Z,1765819591.999 [NAL9602](INFO): GPS fix at 20251215T172631: (36.802802, -121.787925) 2025-12-15T17:26:32.028Z,1765819592.028 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:26:32.028Z,1765819592.028 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:26:39.370Z,1765819599.370 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0022.lzma 2025-12-15T17:26:40.372Z,1765819600.372 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0022.lzma.bak 2025-12-15T17:26:40.372Z,1765819600.372 [DataOverHttps](INFO): SBD MOMSN=26497636 2025-12-15T17:26:56.374Z,1765819616.374 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251215T163415/Express0023.lzma 2025-12-15T17:26:57.376Z,1765819617.376 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0023.lzma.bak 2025-12-15T17:26:57.376Z,1765819617.376 [DataOverHttps](INFO): SBD MOMSN=26497640 2025-12-15T17:26:58.677Z,1765819618.677 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:26:58.677Z,1765819618.677 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:26:58.678Z,1765819618.678 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:27:04.315Z,1765819624.315 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T17:31:59.267Z,1765819919.267 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:31:59.267Z,1765819919.267 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:31:59.267Z,1765819919.267 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:31:59.267Z,1765819919.267 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:31:59.679Z,1765819919.679 [Default:CheckIn:D] Stopped 2025-12-15T17:31:59.679Z,1765819919.679 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:32:00.089Z,1765819920.089 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.735905 min 2025-12-15T17:32:00.089Z,1765819920.089 [Default:CheckIn:E] Stopped 2025-12-15T17:32:00.090Z,1765819920.090 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:32:00.090Z,1765819920.090 [Default:CheckIn] Stopped 2025-12-15T17:32:00.090Z,1765819920.090 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:32:00.090Z,1765819920.090 [Default:CheckIn](INFO): Running loop #8 2025-12-15T17:32:00.090Z,1765819920.090 [Default:CheckIn] Running Loop=8 2025-12-15T17:32:00.090Z,1765819920.090 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:32:00.090Z,1765819920.090 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:32:02.089Z,1765819922.089 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173201.00,A,3648.16657,N,12147.27981,W,0.389,0.00,151225,,,A*76 2025-12-15T17:32:02.091Z,1765819922.091 [NAL9602](INFO): GPS fix at 20251215T173201: (36.802776, -121.787997) 2025-12-15T17:32:02.102Z,1765819922.102 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:32:02.103Z,1765819922.103 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:32:09.526Z,1765819929.526 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0025.lzma 2025-12-15T17:32:10.468Z,1765819930.468 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0025.lzma.bak 2025-12-15T17:32:10.468Z,1765819930.468 [DataOverHttps](INFO): SBD MOMSN=26497649 2025-12-15T17:32:29.570Z,1765819949.570 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251215T163415/Express0026.lzma 2025-12-15T17:32:30.572Z,1765819950.572 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0026.lzma.bak 2025-12-15T17:32:30.572Z,1765819950.572 [DataOverHttps](INFO): SBD MOMSN=26497652 2025-12-15T17:32:31.638Z,1765819951.638 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:32:31.638Z,1765819951.638 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:32:31.639Z,1765819951.639 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:32:59.905Z,1765819979.905 [NAL9602](INFO): SBD MO Status=0, MOMSN=67, MT Status=0, MTMSN=0 2025-12-15T17:32:59.905Z,1765819979.905 [NAL9602](INFO): No messages in MT queue 2025-12-15T17:33:30.615Z,1765820010.615 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T17:37:32.214Z,1765820252.214 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:37:32.214Z,1765820252.214 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:37:32.215Z,1765820252.215 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:37:32.215Z,1765820252.215 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:37:32.613Z,1765820252.613 [Default:CheckIn:D] Stopped 2025-12-15T17:37:32.613Z,1765820252.613 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:37:33.023Z,1765820253.023 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.284802 min 2025-12-15T17:37:33.023Z,1765820253.023 [Default:CheckIn:E] Stopped 2025-12-15T17:37:33.023Z,1765820253.023 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:37:33.023Z,1765820253.023 [Default:CheckIn] Stopped 2025-12-15T17:37:33.024Z,1765820253.024 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:37:33.024Z,1765820253.024 [Default:CheckIn](INFO): Running loop #9 2025-12-15T17:37:33.024Z,1765820253.024 [Default:CheckIn] Running Loop=9 2025-12-15T17:37:33.024Z,1765820253.024 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:37:33.024Z,1765820253.024 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:37:35.029Z,1765820255.029 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173734.00,A,3648.16496,N,12147.27648,W,0.505,0.00,151225,,,A*72 2025-12-15T17:37:35.031Z,1765820255.031 [NAL9602](INFO): GPS fix at 20251215T173734: (36.802749, -121.787941) 2025-12-15T17:37:35.043Z,1765820255.043 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:37:35.043Z,1765820255.043 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:37:43.034Z,1765820263.034 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20251215T163415/Courier0028.lzma 2025-12-15T17:37:44.038Z,1765820264.038 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0028.lzma.bak 2025-12-15T17:37:44.038Z,1765820264.038 [DataOverHttps](INFO): SBD MOMSN=26497663 2025-12-15T17:38:00.078Z,1765820280.078 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20251215T163415/Express0029.lzma 2025-12-15T17:38:01.080Z,1765820281.080 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0029.lzma.bak 2025-12-15T17:38:01.080Z,1765820281.080 [DataOverHttps](INFO): SBD MOMSN=26497666 2025-12-15T17:38:02.139Z,1765820282.139 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:38:02.139Z,1765820282.139 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:38:02.139Z,1765820282.139 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:41:13.195Z,1765820473.195 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T17:41:13.195Z,1765820473.195 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:41:49.550Z,1765820509.550 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:42:00.857Z,1765820520.857 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:42:12.573Z,1765820532.573 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:42:24.693Z,1765820544.693 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:42:36.409Z,1765820556.409 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:42:48.126Z,1765820568.126 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:42:50.149Z,1765820570.149 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T17:42:50.149Z,1765820570.149 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:42:50.556Z,1765820570.556 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-12-15T17:43:00.245Z,1765820580.245 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:43:02.689Z,1765820582.689 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:43:02.689Z,1765820582.689 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:43:02.689Z,1765820582.689 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:43:02.689Z,1765820582.689 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:43:03.095Z,1765820583.095 [Default:CheckIn:D] Stopped 2025-12-15T17:43:03.095Z,1765820583.095 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:43:03.511Z,1765820583.511 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.792834 min 2025-12-15T17:43:03.511Z,1765820583.511 [Default:CheckIn:E] Stopped 2025-12-15T17:43:03.511Z,1765820583.511 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:43:03.511Z,1765820583.511 [Default:CheckIn] Stopped 2025-12-15T17:43:03.512Z,1765820583.512 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:43:03.512Z,1765820583.512 [Default:CheckIn](INFO): Running loop #10 2025-12-15T17:43:03.512Z,1765820583.512 [Default:CheckIn] Running Loop=10 2025-12-15T17:43:03.512Z,1765820583.512 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:43:03.512Z,1765820583.512 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:43:05.501Z,1765820585.501 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174304.00,A,3648.16518,N,12147.27800,W,1.419,0.00,151225,,,A*7A 2025-12-15T17:43:05.504Z,1765820585.504 [NAL9602](INFO): GPS fix at 20251215T174304: (36.802753, -121.787967) 2025-12-15T17:43:05.515Z,1765820585.515 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:43:05.515Z,1765820585.515 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:43:11.967Z,1765820591.967 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T17:43:12.918Z,1765820592.918 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251215T163415/Courier0031.lzma 2025-12-15T17:43:13.920Z,1765820593.920 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0031.lzma.bak 2025-12-15T17:43:13.920Z,1765820593.920 [DataOverHttps](INFO): SBD MOMSN=26497681 2025-12-15T17:43:20.849Z,1765820600.849 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:43:29.858Z,1765820609.858 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20251215T163415/Express0032.lzma 2025-12-15T17:43:30.860Z,1765820610.860 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0032.lzma.bak 2025-12-15T17:43:30.860Z,1765820610.860 [DataOverHttps](INFO): SBD MOMSN=26497703 2025-12-15T17:43:32.175Z,1765820612.175 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:43:32.175Z,1765820612.175 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:43:32.175Z,1765820612.175 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:43:34.181Z,1765820614.181 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:43:37.415Z,1765820617.415 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T17:43:47.916Z,1765820627.916 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:44:02.057Z,1765820642.057 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:44:02.060Z,1765820642.060 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-12-15T17:44:16.197Z,1765820656.197 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:44:29.933Z,1765820669.933 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:44:43.266Z,1765820683.266 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:44:57.005Z,1765820697.005 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:45:10.332Z,1765820710.332 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:45:24.069Z,1765820724.069 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T17:45:45.888Z,1765820745.888 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:45:58.817Z,1765820758.817 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:46:12.145Z,1765820772.145 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:46:25.091Z,1765820785.091 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:46:37.613Z,1765820797.613 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:46:50.542Z,1765820810.542 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:47:03.875Z,1765820823.875 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:47:16.824Z,1765820836.824 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:47:29.324Z,1765820849.324 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:47:42.252Z,1765820862.252 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:47:54.779Z,1765820874.779 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T17:48:08.123Z,1765820888.123 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5. 2025-12-15T17:48:08.126Z,1765820888.126 [BPC1](INFO): Received data from all battery sticks. 2025-12-15T17:48:32.771Z,1765820912.771 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:48:32.771Z,1765820912.771 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:48:32.772Z,1765820912.772 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:48:32.772Z,1765820912.772 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:48:33.181Z,1765820913.181 [Default:CheckIn:D] Stopped 2025-12-15T17:48:33.181Z,1765820913.181 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:48:33.577Z,1765820913.577 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.294279 min 2025-12-15T17:48:33.578Z,1765820913.578 [Default:CheckIn:E] Stopped 2025-12-15T17:48:33.578Z,1765820913.578 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:48:33.578Z,1765820913.578 [Default:CheckIn] Stopped 2025-12-15T17:48:33.578Z,1765820913.578 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:48:33.578Z,1765820913.578 [Default:CheckIn](INFO): Running loop #11 2025-12-15T17:48:33.578Z,1765820913.578 [Default:CheckIn] Running Loop=11 2025-12-15T17:48:33.578Z,1765820913.578 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:48:33.579Z,1765820913.579 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:48:35.589Z,1765820915.589 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174834.00,A,3648.16642,N,12147.28361,W,0.447,340.97,151225,,,A*7E 2025-12-15T17:48:35.591Z,1765820915.591 [NAL9602](INFO): GPS fix at 20251215T174834: (36.802774, -121.788060) 2025-12-15T17:48:35.602Z,1765820915.602 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:48:35.602Z,1765820915.602 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:48:43.330Z,1765820923.330 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20251215T163415/Courier0034.lzma 2025-12-15T17:48:44.332Z,1765820924.332 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0034.lzma.bak 2025-12-15T17:48:44.332Z,1765820924.332 [DataOverHttps](INFO): SBD MOMSN=26497718 2025-12-15T17:49:00.338Z,1765820940.338 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251215T163415/Express0035.lzma 2025-12-15T17:49:01.340Z,1765820941.340 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0035.lzma.bak 2025-12-15T17:49:01.340Z,1765820941.340 [DataOverHttps](INFO): SBD MOMSN=26497721 2025-12-15T17:49:02.666Z,1765820942.666 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:49:02.666Z,1765820942.666 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:49:02.666Z,1765820942.666 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:53:43.841Z,1765821223.841 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T17:53:43.842Z,1765821223.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T17:53:44.239Z,1765821224.239 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-12-15T17:54:03.244Z,1765821243.244 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:54:03.244Z,1765821243.244 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:54:03.245Z,1765821243.245 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:54:03.245Z,1765821243.245 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:54:03.646Z,1765821243.646 [Default:CheckIn:D] Stopped 2025-12-15T17:54:03.646Z,1765821243.646 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:54:04.050Z,1765821244.050 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.802018 min 2025-12-15T17:54:04.050Z,1765821244.050 [Default:CheckIn:E] Stopped 2025-12-15T17:54:04.050Z,1765821244.050 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:54:04.050Z,1765821244.050 [Default:CheckIn] Stopped 2025-12-15T17:54:04.050Z,1765821244.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:54:04.051Z,1765821244.051 [Default:CheckIn](INFO): Running loop #12 2025-12-15T17:54:04.051Z,1765821244.051 [Default:CheckIn] Running Loop=12 2025-12-15T17:54:04.051Z,1765821244.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:54:04.051Z,1765821244.051 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:54:06.058Z,1765821246.058 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175405.00,A,3648.16819,N,12147.27913,W,0.350,157.86,151225,,,A*74 2025-12-15T17:54:06.060Z,1765821246.060 [NAL9602](INFO): GPS fix at 20251215T175405: (36.802803, -121.787986) 2025-12-15T17:54:06.071Z,1765821246.071 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:54:06.071Z,1765821246.071 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:54:13.818Z,1765821253.818 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0037.lzma 2025-12-15T17:54:14.821Z,1765821254.821 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0037.lzma.bak 2025-12-15T17:54:14.821Z,1765821254.821 [DataOverHttps](INFO): SBD MOMSN=26497736 2025-12-15T17:54:33.746Z,1765821273.746 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20251215T163415/Express0038.lzma 2025-12-15T17:54:34.748Z,1765821274.748 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0038.lzma.bak 2025-12-15T17:54:34.748Z,1765821274.748 [DataOverHttps](INFO): SBD MOMSN=26497739 2025-12-15T17:54:36.012Z,1765821276.012 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T17:54:36.012Z,1765821276.012 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T17:54:36.012Z,1765821276.012 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T17:54:38.440Z,1765821278.440 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T17:59:36.589Z,1765821576.589 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T17:59:36.589Z,1765821576.589 [Default:CheckIn:C.Wait] Stopped 2025-12-15T17:59:36.589Z,1765821576.589 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T17:59:36.589Z,1765821576.589 [Default:CheckIn:D] Running Loop=1 2025-12-15T17:59:37.003Z,1765821577.003 [Default:CheckIn:D] Stopped 2025-12-15T17:59:37.003Z,1765821577.003 [Default:CheckIn:E] Running Loop=1 2025-12-15T17:59:37.436Z,1765821577.436 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.357967 min 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn:E] Stopped 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn] Stopped 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn](INFO): Running loop #13 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn] Running Loop=13 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T17:59:37.437Z,1765821577.437 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T17:59:39.412Z,1765821579.412 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175938.00,A,3648.17189,N,12147.28061,W,0.292,157.86,151225,,,A*7A 2025-12-15T17:59:39.414Z,1765821579.414 [NAL9602](INFO): GPS fix at 20251215T175938: (36.802865, -121.788010) 2025-12-15T17:59:39.425Z,1765821579.425 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T17:59:39.425Z,1765821579.425 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T17:59:46.850Z,1765821586.850 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0040.lzma 2025-12-15T17:59:47.852Z,1765821587.852 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0040.lzma.bak 2025-12-15T17:59:47.852Z,1765821587.852 [DataOverHttps](INFO): SBD MOMSN=26497749 2025-12-15T18:00:04.162Z,1765821604.162 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251215T163415/Express0041.lzma 2025-12-15T18:00:05.164Z,1765821605.164 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0041.lzma.bak 2025-12-15T18:00:05.164Z,1765821605.164 [DataOverHttps](INFO): SBD MOMSN=26497754 2025-12-15T18:00:06.536Z,1765821606.536 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:00:06.536Z,1765821606.536 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:00:06.536Z,1765821606.536 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:04:41.201Z,1765821881.201 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-12-15T18:05:07.062Z,1765821907.062 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:05:07.062Z,1765821907.062 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:05:07.062Z,1765821907.062 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:05:07.062Z,1765821907.062 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:05:07.473Z,1765821907.473 [Default:CheckIn:D] Stopped 2025-12-15T18:05:07.474Z,1765821907.474 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:05:07.882Z,1765821907.882 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.865804 min 2025-12-15T18:05:07.882Z,1765821907.882 [Default:CheckIn:E] Stopped 2025-12-15T18:05:07.883Z,1765821907.883 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:05:07.883Z,1765821907.883 [Default:CheckIn] Stopped 2025-12-15T18:05:07.883Z,1765821907.883 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:05:07.883Z,1765821907.883 [Default:CheckIn](INFO): Running loop #14 2025-12-15T18:05:07.883Z,1765821907.883 [Default:CheckIn] Running Loop=14 2025-12-15T18:05:07.883Z,1765821907.883 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:05:07.883Z,1765821907.883 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:05:09.886Z,1765821909.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180509.00,A,3648.17055,N,12147.27748,W,0.214,0.00,151225,,,A*7E 2025-12-15T18:05:09.888Z,1765821909.888 [NAL9602](INFO): GPS fix at 20251215T180509: (36.802842, -121.787958) 2025-12-15T18:05:09.923Z,1765821909.923 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:05:09.923Z,1765821909.923 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:05:17.274Z,1765821917.274 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0043.lzma 2025-12-15T18:05:18.276Z,1765821918.276 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0043.lzma.bak 2025-12-15T18:05:18.276Z,1765821918.276 [DataOverHttps](INFO): SBD MOMSN=26497775 2025-12-15T18:05:34.186Z,1765821934.186 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20251215T163415/Express0044.lzma 2025-12-15T18:05:35.228Z,1765821935.228 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0044.lzma.bak 2025-12-15T18:05:35.228Z,1765821935.228 [DataOverHttps](INFO): SBD MOMSN=26497778 2025-12-15T18:05:36.561Z,1765821936.561 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:05:36.561Z,1765821936.561 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:05:36.561Z,1765821936.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:05:42.607Z,1765821942.607 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:10:37.142Z,1765822237.142 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:10:37.142Z,1765822237.142 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:10:37.142Z,1765822237.142 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:10:37.142Z,1765822237.142 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:10:37.562Z,1765822237.562 [Default:CheckIn:D] Stopped 2025-12-15T18:10:37.562Z,1765822237.562 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:10:37.941Z,1765822237.941 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.367293 min 2025-12-15T18:10:37.942Z,1765822237.942 [Default:CheckIn:E] Stopped 2025-12-15T18:10:37.942Z,1765822237.942 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:10:37.942Z,1765822237.942 [Default:CheckIn] Stopped 2025-12-15T18:10:37.942Z,1765822237.942 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:10:37.943Z,1765822237.943 [Default:CheckIn](INFO): Running loop #15 2025-12-15T18:10:37.943Z,1765822237.943 [Default:CheckIn] Running Loop=15 2025-12-15T18:10:37.943Z,1765822237.943 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:10:37.943Z,1765822237.943 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:10:39.957Z,1765822239.957 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181039.00,A,3648.16829,N,12147.28799,W,1.166,0.00,151225,,,A*7F 2025-12-15T18:10:39.959Z,1765822239.959 [NAL9602](INFO): GPS fix at 20251215T181039: (36.802805, -121.788133) 2025-12-15T18:10:39.975Z,1765822239.975 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:10:39.975Z,1765822239.975 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:10:46.934Z,1765822246.934 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0046.lzma 2025-12-15T18:10:47.937Z,1765822247.937 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0046.lzma.bak 2025-12-15T18:10:47.937Z,1765822247.937 [DataOverHttps](INFO): SBD MOMSN=26497793 2025-12-15T18:11:03.786Z,1765822263.786 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251215T163415/Express0047.lzma 2025-12-15T18:11:04.788Z,1765822264.788 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0047.lzma.bak 2025-12-15T18:11:04.788Z,1765822264.788 [DataOverHttps](INFO): SBD MOMSN=26497796 2025-12-15T18:11:05.832Z,1765822265.832 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:11:05.832Z,1765822265.832 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:11:05.832Z,1765822265.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:11:10.656Z,1765822270.656 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-12-15T18:11:10.738Z,1765822270.738 [NAL9602](ERROR): received: +CSQ:0 OK, 2, 0, 0, 0 OK 2025-12-15T18:14:30.643Z,1765822470.643 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:14:30.643Z,1765822470.643 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:15:15.077Z,1765822515.077 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:15:15.077Z,1765822515.077 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:15:42.547Z,1765822542.547 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-12-15T18:16:06.394Z,1765822566.394 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:16:06.394Z,1765822566.394 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:16:06.394Z,1765822566.394 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:16:06.394Z,1765822566.394 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:16:06.802Z,1765822566.802 [Default:CheckIn:D] Stopped 2025-12-15T18:16:06.802Z,1765822566.802 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:16:07.213Z,1765822567.213 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.854622 min 2025-12-15T18:16:07.213Z,1765822567.213 [Default:CheckIn:E] Stopped 2025-12-15T18:16:07.213Z,1765822567.213 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:16:07.213Z,1765822567.213 [Default:CheckIn] Stopped 2025-12-15T18:16:07.213Z,1765822567.213 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:16:07.214Z,1765822567.214 [Default:CheckIn](INFO): Running loop #16 2025-12-15T18:16:07.214Z,1765822567.214 [Default:CheckIn] Running Loop=16 2025-12-15T18:16:07.214Z,1765822567.214 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:16:07.214Z,1765822567.214 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:16:09.217Z,1765822569.217 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181608.00,A,3648.18316,N,12147.28263,W,0.214,204.19,151225,,,A*7B 2025-12-15T18:16:09.219Z,1765822569.219 [NAL9602](INFO): GPS fix at 20251215T181608: (36.803053, -121.788044) 2025-12-15T18:16:09.246Z,1765822569.246 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:16:09.246Z,1765822569.246 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:16:17.029Z,1765822577.029 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251215T163415/Courier0049.lzma 2025-12-15T18:16:18.032Z,1765822578.032 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0049.lzma.bak 2025-12-15T18:16:18.032Z,1765822578.032 [DataOverHttps](INFO): SBD MOMSN=26497811 2025-12-15T18:16:37.050Z,1765822597.050 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20251215T163415/Express0050.lzma 2025-12-15T18:16:38.052Z,1765822598.052 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0050.lzma.bak 2025-12-15T18:16:38.052Z,1765822598.052 [DataOverHttps](INFO): SBD MOMSN=26497814 2025-12-15T18:16:39.179Z,1765822599.179 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:16:39.179Z,1765822599.179 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:16:39.179Z,1765822599.179 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:16:41.591Z,1765822601.591 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:21:39.758Z,1765822899.758 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:21:39.758Z,1765822899.758 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:21:39.758Z,1765822899.758 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:21:39.759Z,1765822899.759 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:21:40.167Z,1765822900.167 [Default:CheckIn:D] Stopped 2025-12-15T18:21:40.167Z,1765822900.167 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:21:40.581Z,1765822900.581 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.410701 min 2025-12-15T18:21:40.581Z,1765822900.581 [Default:CheckIn:E] Stopped 2025-12-15T18:21:40.581Z,1765822900.581 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:21:40.582Z,1765822900.582 [Default:CheckIn] Stopped 2025-12-15T18:21:40.582Z,1765822900.582 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:21:40.582Z,1765822900.582 [Default:CheckIn](INFO): Running loop #17 2025-12-15T18:21:40.582Z,1765822900.582 [Default:CheckIn] Running Loop=17 2025-12-15T18:21:40.582Z,1765822900.582 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:21:40.582Z,1765822900.582 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:21:42.581Z,1765822902.581 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182141.00,A,3648.16875,N,12147.28337,W,0.836,214.38,151225,,,A*7A 2025-12-15T18:21:42.587Z,1765822902.587 [NAL9602](INFO): GPS fix at 20251215T182141: (36.802813, -121.788056) 2025-12-15T18:21:42.625Z,1765822902.625 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:21:42.625Z,1765822902.625 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:21:50.214Z,1765822910.214 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0052.lzma 2025-12-15T18:21:51.216Z,1765822911.216 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0052.lzma.bak 2025-12-15T18:21:51.216Z,1765822911.216 [DataOverHttps](INFO): SBD MOMSN=26497907 2025-12-15T18:22:07.246Z,1765822927.246 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20251215T163415/Express0053.lzma 2025-12-15T18:22:08.248Z,1765822928.248 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0053.lzma.bak 2025-12-15T18:22:08.248Z,1765822928.248 [DataOverHttps](INFO): SBD MOMSN=26497931 2025-12-15T18:22:09.275Z,1765822929.275 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:22:09.275Z,1765822929.275 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:22:09.275Z,1765822929.275 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:22:13.284Z,1765822933.284 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-12-15T18:22:13.366Z,1765822933.366 [NAL9602](ERROR): received: +CSQ:0 OK, 2, 0, 0, 0 OK 2025-12-15T18:22:28.233Z,1765822948.233 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:22:28.233Z,1765822948.233 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:22:57.720Z,1765822977.720 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:22:57.720Z,1765822977.720 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:23:19.537Z,1765822999.537 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:23:19.537Z,1765822999.537 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:23:48.241Z,1765823028.241 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:23:48.241Z,1765823028.241 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:25:12.268Z,1765823112.268 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:25:12.268Z,1765823112.268 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:26:02.364Z,1765823162.364 [NAL9602](INFO): SBD MO Status=2, MOMSN=68, MT Status=2, MTMSN=0 2025-12-15T18:26:02.364Z,1765823162.364 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:26:44.425Z,1765823204.425 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-12-15T18:27:09.885Z,1765823229.885 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:27:09.885Z,1765823229.885 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:27:09.885Z,1765823229.885 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:27:09.885Z,1765823229.885 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:27:10.290Z,1765823230.290 [Default:CheckIn:D] Stopped 2025-12-15T18:27:10.290Z,1765823230.290 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:27:10.690Z,1765823230.690 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.912752 min 2025-12-15T18:27:10.690Z,1765823230.690 [Default:CheckIn:E] Stopped 2025-12-15T18:27:10.710Z,1765823230.710 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:27:10.710Z,1765823230.710 [Default:CheckIn] Stopped 2025-12-15T18:27:10.710Z,1765823230.710 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:27:10.711Z,1765823230.711 [Default:CheckIn](INFO): Running loop #18 2025-12-15T18:27:10.711Z,1765823230.711 [Default:CheckIn] Running Loop=18 2025-12-15T18:27:10.711Z,1765823230.711 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:27:10.711Z,1765823230.711 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:27:12.701Z,1765823232.701 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182712.00,A,3648.17413,N,12147.28013,W,0.875,217.26,151225,,,A*79 2025-12-15T18:27:12.703Z,1765823232.703 [NAL9602](INFO): GPS fix at 20251215T182712: (36.802902, -121.788002) 2025-12-15T18:27:12.715Z,1765823232.715 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:27:12.715Z,1765823232.715 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:27:20.857Z,1765823240.857 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251215T163415/Courier0055.lzma 2025-12-15T18:27:21.860Z,1765823241.860 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0055.lzma.bak 2025-12-15T18:27:21.860Z,1765823241.860 [DataOverHttps](INFO): SBD MOMSN=26497995 2025-12-15T18:27:37.754Z,1765823257.754 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20251215T163415/Express0056.lzma 2025-12-15T18:27:38.756Z,1765823258.756 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0056.lzma.bak 2025-12-15T18:27:38.756Z,1765823258.756 [DataOverHttps](INFO): SBD MOMSN=26498002 2025-12-15T18:27:39.802Z,1765823259.802 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:27:39.802Z,1765823259.802 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:27:39.802Z,1765823259.802 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:27:45.425Z,1765823265.425 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:28:48.187Z,1765823328.187 [DataOverHttps](IMPORTANT): SBD MTMSN=20251215T182847 2025-12-15T18:28:55.786Z,1765823335.786 [DataOverHttps](INFO): Received command: ibit 2025-12-15T18:28:55.815Z,1765823335.815 [CommandExec](IMPORTANT): got command ibit 2025-12-15T18:28:56.141Z,1765823336.141 [IBIT](IMPORTANT): Beginning Initiated BIT 2025-12-15T18:28:56.141Z,1765823336.141 [IBIT](IMPORTANT): Beginning control surface checks. 2025-12-15T18:28:56.145Z,1765823336.145 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-12-15T18:28:56.787Z,1765823336.787 [DataOverHttps](IMPORTANT): SBD MTMSN=20251215T182855 2025-12-15T18:28:57.738Z,1765823337.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182857.00,A,3648.14302,N,12147.25069,W,1.205,126.73,151225,,,A*7E 2025-12-15T18:28:57.741Z,1765823337.741 [NAL9602](INFO): GPS fix at 20251215T182857: (36.802384, -121.787511) 2025-12-15T18:29:00.687Z,1765823340.687 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002302 CHAN A1 (24V): 0.000383 CHAN A2 (12V): -0.001754 CHAN A3 (5V): -0.001292 CHAN B0 (3.3V): -0.000183 CHAN B1 (3.15aV): 0.000414 CHAN B2 (3.15bV): -0.000196 CHAN B3 (GND): -0.000209 OPEN: -0.000280 Full Scale: +/- 1 mA 2025-12-15T18:29:04.426Z,1765823344.426 [DataOverHttps](INFO): Received command: failc 2025-12-15T18:29:04.451Z,1765823344.451 [CommandExec](IMPORTANT): got command failComponent 2025-12-15T18:29:04.451Z,1765823344.451 [CommandExec](IMPORTANT): Failed components: 2025-12-15T18:29:04.451Z,1765823344.451 [CommandExec](IMPORTANT): No failed Components. 2025-12-15T18:29:28.456Z,1765823368.456 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-12-15T18:29:28.538Z,1765823368.538 [NAL9602](ERROR): received: +CSQ:0 OK, 2, 0, 0, 0 OK 2025-12-15T18:29:42.612Z,1765823382.612 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 3 Latitude: 36.802383 Longitude: -121.787514 2025-12-15T18:29:43.017Z,1765823383.017 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.611000 2025-12-15T18:29:43.017Z,1765823383.017 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2025-12-15T18:29:43.017Z,1765823383.017 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2025-12-15T18:29:43.433Z,1765823383.433 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2025-12-15T18:29:43.433Z,1765823383.433 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2025-12-15T18:29:43.434Z,1765823383.434 [IBIT](IMPORTANT): Pressure:9.550174 PSI 2025-12-15T18:29:43.434Z,1765823383.434 [IBIT](IMPORTANT): Humidity:17.903797 % 2025-12-15T18:29:43.849Z,1765823383.849 [IBIT](IMPORTANT): Vehicle Pitch:-0.876939 degrees 2025-12-15T18:29:43.849Z,1765823383.849 [IBIT](IMPORTANT): Vehicle Roll:-7.745874 degrees 2025-12-15T18:29:43.849Z,1765823383.849 [IBIT](IMPORTANT): Vehicle Heading:2.723032 degrees 2025-12-15T18:29:44.308Z,1765823384.308 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2025-12-15T18:29:44.308Z,1765823384.308 [IBIT](IMPORTANT): buoyancyNeutral: 126.523140 cc 2025-12-15T18:29:44.309Z,1765823384.309 [IBIT](IMPORTANT): massDefault: 1.648935 cm 2025-12-15T18:29:44.309Z,1765823384.309 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2025-12-15T18:29:44.309Z,1765823384.309 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2025-12-15T18:29:44.309Z,1765823384.309 [IBIT](IMPORTANT): IBIT PASSED 2025-12-15T18:29:44.620Z,1765823384.620 [NAL9602](INFO): SBD MO Status=0, MOMSN=68, MT Status=0, MTMSN=0 2025-12-15T18:29:44.620Z,1765823384.620 [NAL9602](INFO): No messages in MT queue 2025-12-15T18:30:15.314Z,1765823415.314 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:32:40.373Z,1765823560.373 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:32:40.373Z,1765823560.373 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:32:40.373Z,1765823560.373 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:32:40.373Z,1765823560.373 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:32:40.775Z,1765823560.775 [Default:CheckIn:D] Stopped 2025-12-15T18:32:40.775Z,1765823560.775 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:32:41.189Z,1765823561.189 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.420841 min 2025-12-15T18:32:41.189Z,1765823561.189 [Default:CheckIn:E] Stopped 2025-12-15T18:32:41.189Z,1765823561.189 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:32:41.189Z,1765823561.189 [Default:CheckIn] Stopped 2025-12-15T18:32:41.189Z,1765823561.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:32:41.189Z,1765823561.189 [Default:CheckIn](INFO): Running loop #19 2025-12-15T18:32:41.189Z,1765823561.189 [Default:CheckIn] Running Loop=19 2025-12-15T18:32:41.190Z,1765823561.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:32:41.190Z,1765823561.190 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:32:43.193Z,1765823563.193 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183242.00,A,3648.15016,N,12147.21787,W,0.058,21.92,151225,,,D*42 2025-12-15T18:32:43.195Z,1765823563.195 [NAL9602](INFO): GPS fix at 20251215T183242: (36.802503, -121.786964) 2025-12-15T18:32:43.225Z,1765823563.225 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:32:43.225Z,1765823563.225 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:32:50.070Z,1765823570.070 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0058.lzma 2025-12-15T18:32:51.072Z,1765823571.072 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0058.lzma.bak 2025-12-15T18:32:51.073Z,1765823571.073 [DataOverHttps](INFO): SBD MOMSN=26498061 2025-12-15T18:32:57.329Z,1765823577.329 [NAL9602](INFO): SBD MO Status=0, MOMSN=69, MT Status=0, MTMSN=0 2025-12-15T18:32:57.329Z,1765823577.329 [NAL9602](INFO): No messages in MT queue 2025-12-15T18:33:07.064Z,1765823587.064 [DataOverHttps](INFO): Sending 929 bytes from file Logs/20251215T163415/Express0059.lzma 2025-12-15T18:33:08.064Z,1765823588.064 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0059.lzma.bak 2025-12-15T18:33:08.064Z,1765823588.064 [DataOverHttps](INFO): SBD MOMSN=26498064 2025-12-15T18:33:09.462Z,1765823589.462 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:33:09.462Z,1765823589.462 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:33:09.462Z,1765823589.462 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:33:28.037Z,1765823608.037 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:38:10.131Z,1765823890.131 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:38:10.131Z,1765823890.131 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:38:10.131Z,1765823890.131 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:38:10.131Z,1765823890.131 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:38:10.508Z,1765823890.508 [Default:CheckIn:D] Stopped 2025-12-15T18:38:10.508Z,1765823890.508 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.916390 min 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn:E] Stopped 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn] Stopped 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn](INFO): Running loop #20 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn] Running Loop=20 2025-12-15T18:38:10.913Z,1765823890.913 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:38:10.914Z,1765823890.914 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:38:12.925Z,1765823892.925 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183812.00,A,3648.15070,N,12147.22121,W,0.078,21.92,151225,,,D*46 2025-12-15T18:38:12.927Z,1765823892.927 [NAL9602](INFO): GPS fix at 20251215T183812: (36.802512, -121.787020) 2025-12-15T18:38:12.938Z,1765823892.938 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:38:12.938Z,1765823892.938 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:38:24.735Z,1765823904.735 [NAL9602](INFO): SBD MO Status=0, MOMSN=70, MT Status=0, MTMSN=0 2025-12-15T18:38:24.735Z,1765823904.735 [NAL9602](INFO): No messages in MT queue 2025-12-15T18:38:27.286Z,1765823907.286 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251215T163415/Courier0061.lzma 2025-12-15T18:38:28.288Z,1765823908.288 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0061.lzma.bak 2025-12-15T18:38:28.289Z,1765823908.289 [DataOverHttps](INFO): SBD MOMSN=26498140 2025-12-15T18:38:44.114Z,1765823924.114 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20251215T163415/Express0063.lzma 2025-12-15T18:38:45.117Z,1765823925.117 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0063.lzma.bak 2025-12-15T18:38:45.117Z,1765823925.117 [DataOverHttps](INFO): SBD MOMSN=26498143 2025-12-15T18:38:46.165Z,1765823926.165 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:38:46.165Z,1765823926.165 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:38:46.166Z,1765823926.166 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:38:55.436Z,1765823935.436 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:43:46.862Z,1765824226.862 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:43:46.862Z,1765824226.862 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:43:46.862Z,1765824226.862 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:43:46.862Z,1765824226.862 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:43:47.249Z,1765824227.249 [Default:CheckIn:D] Stopped 2025-12-15T18:43:47.249Z,1765824227.249 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:43:47.653Z,1765824227.653 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.528743 min 2025-12-15T18:43:47.653Z,1765824227.653 [Default:CheckIn:E] Stopped 2025-12-15T18:43:47.653Z,1765824227.653 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:43:47.653Z,1765824227.653 [Default:CheckIn] Stopped 2025-12-15T18:43:47.653Z,1765824227.653 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:43:47.655Z,1765824227.655 [Default:CheckIn](INFO): Running loop #21 2025-12-15T18:43:47.656Z,1765824227.656 [Default:CheckIn] Running Loop=21 2025-12-15T18:43:47.656Z,1765824227.656 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:43:47.657Z,1765824227.657 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:43:49.709Z,1765824229.709 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184348.00,A,3648.15171,N,12147.21974,W,0.019,104.19,151225,,,D*7C 2025-12-15T18:43:49.712Z,1765824229.712 [NAL9602](INFO): GPS fix at 20251215T184348: (36.802529, -121.786996) 2025-12-15T18:43:49.723Z,1765824229.723 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:43:49.723Z,1765824229.723 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:43:57.278Z,1765824237.278 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20251215T163415/Courier0067.lzma 2025-12-15T18:43:58.280Z,1765824238.280 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0067.lzma.bak 2025-12-15T18:43:58.280Z,1765824238.280 [DataOverHttps](INFO): SBD MOMSN=26498169 2025-12-15T18:44:11.081Z,1765824251.081 [NAL9602](INFO): SBD MO Status=0, MOMSN=71, MT Status=0, MTMSN=0 2025-12-15T18:44:11.081Z,1765824251.081 [NAL9602](INFO): No messages in MT queue 2025-12-15T18:44:14.266Z,1765824254.266 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251215T163415/Express0068.lzma 2025-12-15T18:44:15.269Z,1765824255.269 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0068.lzma.bak 2025-12-15T18:44:15.269Z,1765824255.269 [DataOverHttps](INFO): SBD MOMSN=26498173 2025-12-15T18:44:16.340Z,1765824256.340 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:44:16.340Z,1765824256.340 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:44:16.340Z,1765824256.340 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:44:41.851Z,1765824281.851 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:49:14.613Z,1765824554.613 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:49:17.071Z,1765824557.071 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:49:17.071Z,1765824557.071 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:49:17.071Z,1765824557.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:49:17.071Z,1765824557.071 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:49:17.467Z,1765824557.467 [Default:CheckIn:D] Stopped 2025-12-15T18:49:17.467Z,1765824557.467 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:49:17.862Z,1765824557.862 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.032381 min 2025-12-15T18:49:17.862Z,1765824557.862 [Default:CheckIn:E] Stopped 2025-12-15T18:49:17.862Z,1765824557.862 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:49:17.862Z,1765824557.862 [Default:CheckIn] Stopped 2025-12-15T18:49:17.862Z,1765824557.862 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:49:17.862Z,1765824557.862 [Default:CheckIn](INFO): Running loop #22 2025-12-15T18:49:17.862Z,1765824557.862 [Default:CheckIn] Running Loop=22 2025-12-15T18:49:17.863Z,1765824557.863 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:49:17.863Z,1765824557.863 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:49:19.873Z,1765824559.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184919.00,A,3648.15239,N,12147.22016,W,0.058,104.19,151225,,,D*76 2025-12-15T18:49:19.876Z,1765824559.876 [NAL9602](INFO): GPS fix at 20251215T184919: (36.802540, -121.787003) 2025-12-15T18:49:19.887Z,1765824559.887 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:49:19.887Z,1765824559.887 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:49:26.735Z,1765824566.735 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:49:27.910Z,1765824567.910 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0070.lzma 2025-12-15T18:49:28.912Z,1765824568.912 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0070.lzma.bak 2025-12-15T18:49:28.912Z,1765824568.912 [DataOverHttps](INFO): SBD MOMSN=26498189 2025-12-15T18:49:38.854Z,1765824578.854 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:49:43.313Z,1765824583.313 [NAL9602](INFO): SBD MO Status=2, MOMSN=72, MT Status=2, MTMSN=0 2025-12-15T18:49:43.313Z,1765824583.313 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:49:45.042Z,1765824585.042 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251215T163415/Express0071.lzma 2025-12-15T18:49:46.044Z,1765824586.044 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0071.lzma.bak 2025-12-15T18:49:46.044Z,1765824586.044 [DataOverHttps](INFO): SBD MOMSN=26498192 2025-12-15T18:49:47.349Z,1765824587.349 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:49:47.350Z,1765824587.350 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:49:47.350Z,1765824587.350 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:49:50.973Z,1765824590.973 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:49:59.069Z,1765824599.069 [NAL9602](INFO): SBD MO Status=2, MOMSN=72, MT Status=2, MTMSN=0 2025-12-15T18:49:59.069Z,1765824599.069 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T18:50:02.689Z,1765824602.689 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:50:07.145Z,1765824607.145 [NAL9602](INFO): SBD MO Status=0, MOMSN=72, MT Status=0, MTMSN=0 2025-12-15T18:50:07.145Z,1765824607.145 [NAL9602](INFO): No messages in MT queue 2025-12-15T18:50:14.001Z,1765824614.001 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:50:25.374Z,1765824625.374 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:50:36.681Z,1765824636.681 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-12-15T18:50:37.895Z,1765824637.895 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T18:50:46.382Z,1765824646.382 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:51:00.113Z,1765824660.113 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:51:13.445Z,1765824673.445 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:51:27.181Z,1765824687.181 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:51:41.321Z,1765824701.321 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:51:55.464Z,1765824715.464 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:52:08.793Z,1765824728.793 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:52:22.532Z,1765824742.532 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:52:36.321Z,1765824756.321 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:52:49.654Z,1765824769.654 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-12-15T18:53:11.470Z,1765824791.470 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:53:24.405Z,1765824804.405 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:53:38.133Z,1765824818.133 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:53:51.466Z,1765824831.466 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:54:04.797Z,1765824844.797 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:54:18.129Z,1765824858.129 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:54:31.465Z,1765824871.465 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:54:43.988Z,1765824883.988 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:54:48.045Z,1765824888.045 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T18:54:48.045Z,1765824888.045 [Default:CheckIn:C.Wait] Stopped 2025-12-15T18:54:48.045Z,1765824888.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T18:54:48.046Z,1765824888.046 [Default:CheckIn:D] Running Loop=1 2025-12-15T18:54:48.445Z,1765824888.445 [Default:CheckIn:D] Stopped 2025-12-15T18:54:48.445Z,1765824888.445 [Default:CheckIn:E] Running Loop=1 2025-12-15T18:54:48.857Z,1765824888.857 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.548665 min 2025-12-15T18:54:48.857Z,1765824888.857 [Default:CheckIn:E] Stopped 2025-12-15T18:54:48.858Z,1765824888.858 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T18:54:48.858Z,1765824888.858 [Default:CheckIn] Stopped 2025-12-15T18:54:48.858Z,1765824888.858 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T18:54:48.858Z,1765824888.858 [Default:CheckIn](INFO): Running loop #23 2025-12-15T18:54:48.858Z,1765824888.858 [Default:CheckIn] Running Loop=23 2025-12-15T18:54:48.858Z,1765824888.858 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T18:54:48.858Z,1765824888.858 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T18:54:50.884Z,1765824890.884 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185450.00,A,3648.15074,N,12147.22233,W,0.019,104.19,151225,,,A*79 2025-12-15T18:54:50.886Z,1765824890.886 [NAL9602](INFO): GPS fix at 20251215T185450: (36.802512, -121.787039) 2025-12-15T18:54:50.905Z,1765824890.905 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T18:54:50.905Z,1765824890.905 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T18:54:57.328Z,1765824897.328 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:54:58.161Z,1765824898.161 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0073.lzma 2025-12-15T18:54:59.164Z,1765824899.164 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0073.lzma.bak 2025-12-15T18:54:59.164Z,1765824899.164 [DataOverHttps](INFO): SBD MOMSN=26498209 2025-12-15T18:55:08.645Z,1765824908.645 [NAL9602](INFO): SBD MO Status=0, MOMSN=73, MT Status=0, MTMSN=0 2025-12-15T18:55:08.645Z,1765824908.645 [NAL9602](INFO): No messages in MT queue 2025-12-15T18:55:09.450Z,1765824909.450 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:55:15.186Z,1765824915.186 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251215T163415/Express0074.lzma 2025-12-15T18:55:16.188Z,1765824916.188 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0074.lzma.bak 2025-12-15T18:55:16.188Z,1765824916.188 [DataOverHttps](INFO): SBD MOMSN=26498214 2025-12-15T18:55:17.216Z,1765824917.216 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T18:55:17.216Z,1765824917.216 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T18:55:17.216Z,1765824917.216 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T18:55:22.378Z,1765824922.378 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-12-15T18:55:34.908Z,1765824934.908 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5. 2025-12-15T18:55:34.911Z,1765824934.911 [BPC1](INFO): Received data from all battery sticks. 2025-12-15T18:55:39.351Z,1765824939.351 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:00:17.813Z,1765825217.813 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:00:17.813Z,1765825217.813 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:00:17.813Z,1765825217.813 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:00:17.813Z,1765825217.813 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:00:18.211Z,1765825218.211 [Default:CheckIn:D] Stopped 2025-12-15T19:00:18.211Z,1765825218.211 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:00:18.623Z,1765825218.623 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.044775 min 2025-12-15T19:00:18.623Z,1765825218.623 [Default:CheckIn:E] Stopped 2025-12-15T19:00:18.623Z,1765825218.623 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:00:18.623Z,1765825218.623 [Default:CheckIn] Stopped 2025-12-15T19:00:18.623Z,1765825218.623 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:00:18.624Z,1765825218.624 [Default:CheckIn](INFO): Running loop #24 2025-12-15T19:00:18.624Z,1765825218.624 [Default:CheckIn] Running Loop=24 2025-12-15T19:00:18.624Z,1765825218.624 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:00:18.624Z,1765825218.624 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:00:20.621Z,1765825220.621 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190019.00,A,3648.14956,N,12147.22237,W,0.019,104.19,151225,,,A*78 2025-12-15T19:00:20.623Z,1765825220.623 [NAL9602](INFO): GPS fix at 20251215T190019: (36.802493, -121.787040) 2025-12-15T19:00:20.670Z,1765825220.670 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:00:20.670Z,1765825220.670 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:00:31.129Z,1765825231.129 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20251215T163415/Courier0076.lzma 2025-12-15T19:00:32.132Z,1765825232.132 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0076.lzma.bak 2025-12-15T19:00:32.132Z,1765825232.132 [DataOverHttps](INFO): SBD MOMSN=26498223 2025-12-15T19:00:36.021Z,1765825236.021 [NAL9602](INFO): SBD MO Status=0, MOMSN=74, MT Status=0, MTMSN=0 2025-12-15T19:00:36.021Z,1765825236.021 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:00:48.126Z,1765825248.126 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20251215T163415/Express0077.lzma 2025-12-15T19:00:49.128Z,1765825249.128 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0077.lzma.bak 2025-12-15T19:00:49.128Z,1765825249.128 [DataOverHttps](INFO): SBD MOMSN=26498232 2025-12-15T19:00:50.193Z,1765825250.193 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:00:50.193Z,1765825250.193 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:00:50.194Z,1765825250.194 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:01:06.718Z,1765825266.718 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:05:50.740Z,1765825550.740 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:05:50.740Z,1765825550.740 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:05:50.740Z,1765825550.740 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:05:50.741Z,1765825550.741 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:05:51.170Z,1765825551.170 [Default:CheckIn:D] Stopped 2025-12-15T19:05:51.170Z,1765825551.170 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:05:51.559Z,1765825551.559 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.594092 min 2025-12-15T19:05:51.559Z,1765825551.559 [Default:CheckIn:E] Stopped 2025-12-15T19:05:51.559Z,1765825551.559 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:05:51.559Z,1765825551.559 [Default:CheckIn] Stopped 2025-12-15T19:05:51.560Z,1765825551.560 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:05:51.560Z,1765825551.560 [Default:CheckIn](INFO): Running loop #25 2025-12-15T19:05:51.560Z,1765825551.560 [Default:CheckIn] Running Loop=25 2025-12-15T19:05:51.560Z,1765825551.560 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:05:51.560Z,1765825551.560 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:05:53.563Z,1765825553.563 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190552.00,A,3648.14856,N,12147.22136,W,0.117,104.19,151225,,,A*7E 2025-12-15T19:05:53.565Z,1765825553.565 [NAL9602](INFO): GPS fix at 20251215T190552: (36.802476, -121.787023) 2025-12-15T19:05:53.576Z,1765825553.576 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:05:53.576Z,1765825553.576 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:06:01.450Z,1765825561.450 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251215T163415/Courier0079.lzma 2025-12-15T19:06:02.453Z,1765825562.453 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0079.lzma.bak 2025-12-15T19:06:02.454Z,1765825562.454 [DataOverHttps](INFO): SBD MOMSN=26498279 2025-12-15T19:06:10.129Z,1765825570.129 [NAL9602](INFO): SBD MO Status=0, MOMSN=75, MT Status=0, MTMSN=0 2025-12-15T19:06:10.129Z,1765825570.129 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:06:19.282Z,1765825579.282 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251215T163415/Express0080.lzma 2025-12-15T19:06:20.284Z,1765825580.284 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0080.lzma.bak 2025-12-15T19:06:20.284Z,1765825580.284 [DataOverHttps](INFO): SBD MOMSN=26498285 2025-12-15T19:06:21.466Z,1765825581.466 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:06:21.466Z,1765825581.466 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:06:21.466Z,1765825581.466 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:06:40.884Z,1765825600.884 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:11:22.063Z,1765825882.063 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:11:22.063Z,1765825882.063 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:11:22.063Z,1765825882.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:11:22.064Z,1765825882.064 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:11:22.473Z,1765825882.473 [Default:CheckIn:D] Stopped 2025-12-15T19:11:22.473Z,1765825882.473 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:11:22.891Z,1765825882.891 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.115804 min 2025-12-15T19:11:22.891Z,1765825882.891 [Default:CheckIn:E] Stopped 2025-12-15T19:11:22.891Z,1765825882.891 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:11:22.891Z,1765825882.891 [Default:CheckIn] Stopped 2025-12-15T19:11:22.891Z,1765825882.891 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:11:22.892Z,1765825882.892 [Default:CheckIn](INFO): Running loop #26 2025-12-15T19:11:22.892Z,1765825882.892 [Default:CheckIn] Running Loop=26 2025-12-15T19:11:22.892Z,1765825882.892 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:11:22.892Z,1765825882.892 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:11:24.889Z,1765825884.889 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191124.00,A,3648.14936,N,12147.22002,W,0.019,0.00,151225,,,A*79 2025-12-15T19:11:24.892Z,1765825884.892 [NAL9602](INFO): GPS fix at 20251215T191124: (36.802489, -121.787000) 2025-12-15T19:11:24.902Z,1765825884.902 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:11:24.902Z,1765825884.902 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:11:32.841Z,1765825892.841 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0082.lzma 2025-12-15T19:11:33.844Z,1765825893.844 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0082.lzma.bak 2025-12-15T19:11:33.844Z,1765825893.844 [DataOverHttps](INFO): SBD MOMSN=26498331 2025-12-15T19:11:39.849Z,1765825899.849 [NAL9602](INFO): SBD MO Status=0, MOMSN=76, MT Status=0, MTMSN=0 2025-12-15T19:11:39.849Z,1765825899.849 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:11:49.654Z,1765825909.654 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20251215T163415/Express0083.lzma 2025-12-15T19:11:50.656Z,1765825910.656 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0083.lzma.bak 2025-12-15T19:11:50.656Z,1765825910.656 [DataOverHttps](INFO): SBD MOMSN=26498337 2025-12-15T19:11:51.982Z,1765825911.982 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:11:51.982Z,1765825911.982 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:11:51.982Z,1765825911.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:12:10.546Z,1765825930.546 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:16:52.575Z,1765826212.575 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:16:52.576Z,1765826212.576 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:16:52.576Z,1765826212.576 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:16:52.576Z,1765826212.576 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:16:52.973Z,1765826212.973 [Default:CheckIn:D] Stopped 2025-12-15T19:16:52.973Z,1765826212.973 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:16:53.378Z,1765826213.378 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.624137 min 2025-12-15T19:16:53.379Z,1765826213.379 [Default:CheckIn:E] Stopped 2025-12-15T19:16:53.379Z,1765826213.379 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:16:53.379Z,1765826213.379 [Default:CheckIn] Stopped 2025-12-15T19:16:53.379Z,1765826213.379 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:16:53.380Z,1765826213.380 [Default:CheckIn](INFO): Running loop #27 2025-12-15T19:16:53.380Z,1765826213.380 [Default:CheckIn] Running Loop=27 2025-12-15T19:16:53.380Z,1765826213.380 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:16:53.380Z,1765826213.380 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:16:55.388Z,1765826215.388 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191654.00,A,3648.15140,N,12147.21837,W,0.117,68.25,151225,,,A*4A 2025-12-15T19:16:55.390Z,1765826215.390 [NAL9602](INFO): GPS fix at 20251215T191654: (36.802523, -121.786973) 2025-12-15T19:16:55.427Z,1765826215.427 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:16:55.427Z,1765826215.427 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:17:03.217Z,1765826223.217 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0085.lzma 2025-12-15T19:17:04.220Z,1765826224.220 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0085.lzma.bak 2025-12-15T19:17:04.220Z,1765826224.220 [DataOverHttps](INFO): SBD MOMSN=26498452 2025-12-15T19:17:11.149Z,1765826231.149 [NAL9602](INFO): SBD MO Status=0, MOMSN=77, MT Status=0, MTMSN=0 2025-12-15T19:17:11.149Z,1765826231.149 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:17:20.106Z,1765826240.106 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20251215T163415/Express0086.lzma 2025-12-15T19:17:21.108Z,1765826241.108 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0086.lzma.bak 2025-12-15T19:17:21.108Z,1765826241.108 [DataOverHttps](INFO): SBD MOMSN=26498456 2025-12-15T19:17:22.475Z,1765826242.475 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:17:22.475Z,1765826242.475 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:17:22.475Z,1765826242.475 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:17:41.848Z,1765826261.848 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:22:23.077Z,1765826543.077 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:22:23.077Z,1765826543.077 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:22:23.077Z,1765826543.077 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:22:23.077Z,1765826543.077 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:22:23.474Z,1765826543.474 [Default:CheckIn:D] Stopped 2025-12-15T19:22:23.474Z,1765826543.474 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:22:23.879Z,1765826543.879 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.132487 min 2025-12-15T19:22:23.879Z,1765826543.879 [Default:CheckIn:E] Stopped 2025-12-15T19:22:23.880Z,1765826543.880 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:22:23.880Z,1765826543.880 [Default:CheckIn] Stopped 2025-12-15T19:22:23.880Z,1765826543.880 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:22:23.880Z,1765826543.880 [Default:CheckIn](INFO): Running loop #28 2025-12-15T19:22:23.880Z,1765826543.880 [Default:CheckIn] Running Loop=28 2025-12-15T19:22:23.880Z,1765826543.880 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:22:23.880Z,1765826543.880 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:22:25.881Z,1765826545.881 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192225.00,A,3648.15338,N,12147.21743,W,0.564,68.25,151225,,,D*4F 2025-12-15T19:22:25.883Z,1765826545.883 [NAL9602](INFO): GPS fix at 20251215T192225: (36.802556, -121.786957) 2025-12-15T19:22:25.915Z,1765826545.915 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:22:25.915Z,1765826545.915 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:22:33.313Z,1765826553.313 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0088.lzma 2025-12-15T19:22:34.316Z,1765826554.316 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0088.lzma.bak 2025-12-15T19:22:34.316Z,1765826554.316 [DataOverHttps](INFO): SBD MOMSN=26498522 2025-12-15T19:22:38.409Z,1765826558.409 [NAL9602](INFO): SBD MO Status=0, MOMSN=78, MT Status=0, MTMSN=0 2025-12-15T19:22:38.409Z,1765826558.409 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:22:50.194Z,1765826570.194 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20251215T163415/Express0089.lzma 2025-12-15T19:22:51.197Z,1765826571.197 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0089.lzma.bak 2025-12-15T19:22:51.197Z,1765826571.197 [DataOverHttps](INFO): SBD MOMSN=26498525 2025-12-15T19:22:52.563Z,1765826572.563 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:22:52.563Z,1765826572.563 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:22:52.563Z,1765826572.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:23:09.111Z,1765826589.111 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:27:53.137Z,1765826873.137 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:27:53.137Z,1765826873.137 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:27:53.137Z,1765826873.137 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:27:53.138Z,1765826873.138 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:27:53.541Z,1765826873.541 [Default:CheckIn:D] Stopped 2025-12-15T19:27:53.541Z,1765826873.541 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:27:53.941Z,1765826873.941 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.633610 min 2025-12-15T19:27:53.942Z,1765826873.942 [Default:CheckIn:E] Stopped 2025-12-15T19:27:53.942Z,1765826873.942 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:27:53.942Z,1765826873.942 [Default:CheckIn] Stopped 2025-12-15T19:27:53.942Z,1765826873.942 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:27:53.958Z,1765826873.958 [Default:CheckIn](INFO): Running loop #29 2025-12-15T19:27:53.958Z,1765826873.958 [Default:CheckIn] Running Loop=29 2025-12-15T19:27:53.958Z,1765826873.958 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:27:53.958Z,1765826873.958 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:27:55.948Z,1765826875.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192755.00,A,3648.39578,N,12147.11264,W,4.976,8.10,151225,,,D*79 2025-12-15T19:27:55.951Z,1765826875.951 [NAL9602](INFO): GPS fix at 20251215T192755: (36.806596, -121.785211) 2025-12-15T19:27:55.961Z,1765826875.961 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:27:55.961Z,1765826875.961 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:28:03.262Z,1765826883.262 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0091.lzma 2025-12-15T19:28:04.262Z,1765826884.262 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0091.lzma.bak 2025-12-15T19:28:04.262Z,1765826884.262 [DataOverHttps](INFO): SBD MOMSN=26498547 2025-12-15T19:28:11.313Z,1765826891.313 [NAL9602](INFO): SBD MO Status=0, MOMSN=79, MT Status=0, MTMSN=0 2025-12-15T19:28:11.313Z,1765826891.313 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:28:22.174Z,1765826902.174 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20251215T163415/Express0092.lzma 2025-12-15T19:28:23.176Z,1765826903.176 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0092.lzma.bak 2025-12-15T19:28:23.177Z,1765826903.177 [DataOverHttps](INFO): SBD MOMSN=26498550 2025-12-15T19:28:24.289Z,1765826904.289 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:28:24.289Z,1765826904.289 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:28:24.289Z,1765826904.289 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:28:42.051Z,1765826922.051 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:33:24.861Z,1765827204.861 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:33:24.861Z,1765827204.861 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:33:24.861Z,1765827204.861 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:33:24.861Z,1765827204.861 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:33:25.270Z,1765827205.270 [Default:CheckIn:D] Stopped 2025-12-15T19:33:25.270Z,1765827205.270 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.162419 min 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn:E] Stopped 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn] Stopped 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn](INFO): Running loop #30 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn] Running Loop=30 2025-12-15T19:33:25.687Z,1765827205.687 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:33:25.688Z,1765827205.688 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:33:27.682Z,1765827207.682 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193326.00,A,3648.23872,N,12148.04747,W,15.862,261.16,151225,,,D*44 2025-12-15T19:33:27.684Z,1765827207.684 [NAL9602](INFO): GPS fix at 20251215T193326: (36.803979, -121.800791) 2025-12-15T19:33:27.695Z,1765827207.695 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:33:27.695Z,1765827207.695 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:33:35.082Z,1765827215.082 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0094.lzma 2025-12-15T19:33:36.084Z,1765827216.084 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0094.lzma.bak 2025-12-15T19:33:36.085Z,1765827216.085 [DataOverHttps](INFO): SBD MOMSN=26498611 2025-12-15T19:33:52.010Z,1765827232.010 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251215T163415/Express0095.lzma 2025-12-15T19:33:53.012Z,1765827233.012 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0095.lzma.bak 2025-12-15T19:33:53.012Z,1765827233.012 [DataOverHttps](INFO): SBD MOMSN=26498614 2025-12-15T19:33:53.949Z,1765827233.949 [NAL9602](INFO): SBD MO Status=2, MOMSN=80, MT Status=2, MTMSN=0 2025-12-15T19:33:53.949Z,1765827233.949 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T19:33:54.386Z,1765827234.386 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:33:54.386Z,1765827234.386 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:33:54.386Z,1765827234.386 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:34:39.650Z,1765827279.650 [NAL9602](INFO): SBD MO Status=2, MOMSN=80, MT Status=2, MTMSN=0 2025-12-15T19:34:39.651Z,1765827279.651 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T19:34:54.996Z,1765827294.996 [NAL9602](INFO): SBD MO Status=0, MOMSN=80, MT Status=0, MTMSN=0 2025-12-15T19:34:54.996Z,1765827294.996 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:35:25.700Z,1765827325.700 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:38:54.994Z,1765827534.994 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:38:54.994Z,1765827534.994 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:38:54.995Z,1765827534.995 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:38:54.995Z,1765827534.995 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:38:55.405Z,1765827535.405 [Default:CheckIn:D] Stopped 2025-12-15T19:38:55.405Z,1765827535.405 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:38:55.825Z,1765827535.825 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.664681 min 2025-12-15T19:38:55.825Z,1765827535.825 [Default:CheckIn:E] Stopped 2025-12-15T19:38:55.825Z,1765827535.825 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:38:55.825Z,1765827535.825 [Default:CheckIn] Stopped 2025-12-15T19:38:55.825Z,1765827535.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:38:55.825Z,1765827535.825 [Default:CheckIn](INFO): Running loop #31 2025-12-15T19:38:55.826Z,1765827535.826 [Default:CheckIn] Running Loop=31 2025-12-15T19:38:55.826Z,1765827535.826 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:38:55.826Z,1765827535.826 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:38:57.813Z,1765827537.813 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193857.00,A,3647.89331,N,12150.27876,W,22.918,262.01,151225,,,D*42 2025-12-15T19:38:57.816Z,1765827537.816 [NAL9602](INFO): GPS fix at 20251215T193857: (36.798222, -121.837979) 2025-12-15T19:38:57.843Z,1765827537.843 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:38:57.843Z,1765827537.843 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:39:05.822Z,1765827545.822 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0097.lzma 2025-12-15T19:39:06.824Z,1765827546.824 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0097.lzma.bak 2025-12-15T19:39:06.824Z,1765827546.824 [DataOverHttps](INFO): SBD MOMSN=26498636 2025-12-15T19:39:22.838Z,1765827562.838 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251215T163415/Express0098.lzma 2025-12-15T19:39:23.841Z,1765827563.841 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0098.lzma.bak 2025-12-15T19:39:23.841Z,1765827563.841 [DataOverHttps](INFO): SBD MOMSN=26498640 2025-12-15T19:39:24.481Z,1765827564.481 [NAL9602](INFO): SBD MO Status=2, MOMSN=81, MT Status=2, MTMSN=0 2025-12-15T19:39:24.481Z,1765827564.481 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T19:39:24.911Z,1765827564.911 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:39:24.911Z,1765827564.911 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:39:24.911Z,1765827564.911 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:40:03.669Z,1765827603.669 [NAL9602](INFO): SBD MO Status=0, MOMSN=81, MT Status=0, MTMSN=0 2025-12-15T19:40:03.669Z,1765827603.669 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:40:34.383Z,1765827634.383 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:44:25.478Z,1765827865.478 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:44:25.478Z,1765827865.478 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:44:25.478Z,1765827865.478 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:44:25.478Z,1765827865.478 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:44:25.895Z,1765827865.895 [Default:CheckIn:D] Stopped 2025-12-15T19:44:25.895Z,1765827865.895 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:44:26.303Z,1765827866.303 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.172835 min 2025-12-15T19:44:26.303Z,1765827866.303 [Default:CheckIn:E] Stopped 2025-12-15T19:44:26.303Z,1765827866.303 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:44:26.303Z,1765827866.303 [Default:CheckIn] Stopped 2025-12-15T19:44:26.304Z,1765827866.304 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:44:26.304Z,1765827866.304 [Default:CheckIn](INFO): Running loop #32 2025-12-15T19:44:26.304Z,1765827866.304 [Default:CheckIn] Running Loop=32 2025-12-15T19:44:26.304Z,1765827866.304 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:44:26.304Z,1765827866.304 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:44:28.297Z,1765827868.297 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194427.00,A,3647.75914,N,12150.68760,W,0.486,113.60,151225,,,D*7B 2025-12-15T19:44:28.299Z,1765827868.299 [NAL9602](INFO): GPS fix at 20251215T194427: (36.795986, -121.844793) 2025-12-15T19:44:28.339Z,1765827868.339 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:44:28.339Z,1765827868.339 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:44:36.685Z,1765827876.685 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20251215T163415/Courier0100.lzma 2025-12-15T19:44:37.688Z,1765827877.688 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0100.lzma.bak 2025-12-15T19:44:37.688Z,1765827877.688 [DataOverHttps](INFO): SBD MOMSN=26498659 2025-12-15T19:44:53.711Z,1765827893.711 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20251215T163415/Express0101.lzma 2025-12-15T19:44:54.713Z,1765827894.713 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Express0101.lzma.bak 2025-12-15T19:44:54.713Z,1765827894.713 [DataOverHttps](INFO): SBD MOMSN=26498663 2025-12-15T19:44:55.781Z,1765827895.781 [Default:CheckIn:Read_Iridium] Stopped 2025-12-15T19:44:55.782Z,1765827895.782 [Default:CheckIn:C.Wait] Running Loop=1 2025-12-15T19:44:55.782Z,1765827895.782 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-12-15T19:45:06.274Z,1765827906.274 [NAL9602](INFO): SBD MO Status=2, MOMSN=82, MT Status=2, MTMSN=0 2025-12-15T19:45:06.275Z,1765827906.275 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-12-15T19:45:21.625Z,1765827921.625 [NAL9602](INFO): SBD MO Status=0, MOMSN=82, MT Status=0, MTMSN=0 2025-12-15T19:45:21.625Z,1765827921.625 [NAL9602](INFO): No messages in MT queue 2025-12-15T19:45:52.331Z,1765827952.331 [NAL9602](INFO): Not Powering down - fast GPS 2025-12-15T19:49:56.365Z,1765828196.365 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-12-15T19:49:56.365Z,1765828196.365 [Default:CheckIn:C.Wait] Stopped 2025-12-15T19:49:56.365Z,1765828196.365 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-12-15T19:49:56.365Z,1765828196.365 [Default:CheckIn:D] Running Loop=1 2025-12-15T19:49:56.770Z,1765828196.770 [Default:CheckIn:D] Stopped 2025-12-15T19:49:56.770Z,1765828196.770 [Default:CheckIn:E] Running Loop=1 2025-12-15T19:49:57.180Z,1765828197.180 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 191.687435 min 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn:E] Stopped 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn] Stopped 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn](INFO): Running loop #33 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn] Running Loop=33 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-12-15T19:49:57.181Z,1765828197.181 [Default:CheckIn:Read_GPS] Running Loop=1 2025-12-15T19:49:59.185Z,1765828199.185 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194958.00,A,3647.74810,N,12150.72615,W,0.233,28.69,151225,,,D*4A 2025-12-15T19:49:59.187Z,1765828199.187 [NAL9602](INFO): GPS fix at 20251215T194958: (36.795802, -121.845436) 2025-12-15T19:49:59.215Z,1765828199.215 [Default:CheckIn:Read_GPS] Stopped 2025-12-15T19:49:59.215Z,1765828199.215 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-12-15T19:50:06.594Z,1765828206.594 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251215T163415/Courier0103.lzma 2025-12-15T19:50:07.596Z,1765828207.596 [DataOverHttps](INFO): Moved sent file to Logs/20251215T163415/Courier0103.lzma.bak 2025-12-15T19:50:07.597Z,1765828207.597 [DataOverHttps](IMPORTANT): SBD MOMSN=26498676, MTMSN=20251215T195006 2025-12-15T19:50:14.133Z,1765828214.133 [NAL9602](INFO): SBD MO Status=0, MOMSN=83, MT Status=0, MTMSN=0 2025-12-15T19:50:14.133Z,1765828214.133 [NAL9602](INFO): No messages in MT queue