2025-09-23T15:33:15.956Z,1758641595.956 [Supervisor](DEBUG): Initializing supervisor. 2025-09-23T15:33:15.961Z,1758641595.961 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-09-23T15:33:15.961Z,1758641595.961 [SyncHandler](INFO): Protected caller Thread ID is 836 2025-09-23T15:33:15.962Z,1758641595.962 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-09-23T15:33:15.962Z,1758641595.962 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-09-23T15:33:15.963Z,1758641595.963 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837 2025-09-23T15:33:15.967Z,1758641595.967 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-09-23T15:33:15.987Z,1758641595.987 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-09-23T15:33:15.988Z,1758641595.988 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-09-23T15:33:15.989Z,1758641595.989 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838 2025-09-23T15:33:15.993Z,1758641595.993 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-09-23T15:33:15.994Z,1758641595.994 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-09-23T15:33:15.994Z,1758641595.994 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839 2025-09-23T15:33:15.997Z,1758641595.997 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-09-23T15:33:15.998Z,1758641595.998 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-09-23T15:33:15.998Z,1758641595.998 [logger ThreadHandler](INFO): Protected caller Thread ID is 840 2025-09-23T15:33:16.002Z,1758641596.002 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-09-23T15:33:16.002Z,1758641596.002 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-09-23T15:33:16.007Z,1758641596.007 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-09-23T15:33:16.277Z,1758641596.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-09-23T15:33:16.279Z,1758641596.279 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-09-23T15:33:16.379Z,1758641596.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-09-23T15:33:16.379Z,1758641596.379 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-09-23T15:33:16.906Z,1758641596.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-09-23T15:33:16.907Z,1758641596.907 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-09-23T15:33:17.263Z,1758641597.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-09-23T15:33:17.265Z,1758641597.265 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-09-23T15:33:17.371Z,1758641597.371 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-09-23T15:33:17.373Z,1758641597.373 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-09-23T15:33:17.798Z,1758641597.798 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-09-23T15:33:17.800Z,1758641597.800 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-09-23T15:33:18.038Z,1758641598.038 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-09-23T15:33:18.040Z,1758641598.040 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-09-23T15:33:18.591Z,1758641598.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-09-23T15:33:18.593Z,1758641598.593 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-09-23T15:33:18.743Z,1758641598.743 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-09-23T15:33:18.745Z,1758641598.745 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-09-23T15:33:18.836Z,1758641598.836 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-09-23T15:33:20.108Z,1758641600.108 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-09-23T15:33:20.109Z,1758641600.109 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-09-23T15:33:20.507Z,1758641600.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-09-23T15:33:20.508Z,1758641600.508 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-09-23T15:33:20.700Z,1758641600.700 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-09-23T15:33:20.702Z,1758641600.702 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-09-23T15:33:20.825Z,1758641600.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-09-23T15:33:20.826Z,1758641600.826 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-09-23T15:33:21.066Z,1758641601.066 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-09-23T15:33:21.067Z,1758641601.067 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-09-23T15:33:21.335Z,1758641601.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-09-23T15:33:21.337Z,1758641601.337 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2025-09-23T15:33:21.340Z,1758641601.340 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2025-09-23T15:33:21.438Z,1758641601.438 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2025-09-23T15:33:21.550Z,1758641601.550 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2025-09-23T15:33:21.643Z,1758641601.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2025-09-23T15:33:21.756Z,1758641601.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2025-09-23T15:33:21.862Z,1758641601.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2025-09-23T15:33:21.991Z,1758641601.991 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2025-09-23T15:33:22.151Z,1758641602.151 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2025-09-23T15:33:22.307Z,1758641602.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2025-09-23T15:33:22.427Z,1758641602.427 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2025-09-23T15:33:22.721Z,1758641602.721 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-09-23T15:33:22.722Z,1758641602.722 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-09-23T15:33:22.732Z,1758641602.732 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-09-23T15:33:22.807Z,1758641602.807 [VerticalControl](DEBUG): Construct VerticalControl. 2025-09-23T15:33:22.871Z,1758641602.871 [VerticalControl] Loaded 2025-09-23T15:33:22.871Z,1758641602.871 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-09-23T15:33:22.874Z,1758641602.874 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-09-23T15:33:22.923Z,1758641602.923 [HorizontalControl] Loaded 2025-09-23T15:33:22.923Z,1758641602.923 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-09-23T15:33:22.926Z,1758641602.926 [SpeedControl](DEBUG): Construct SpeedControl. 2025-09-23T15:33:22.929Z,1758641602.929 [SpeedControl] Loaded 2025-09-23T15:33:22.929Z,1758641602.929 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-09-23T15:33:22.932Z,1758641602.932 [LoopControl](DEBUG): Construct LoopControl. 2025-09-23T15:33:22.933Z,1758641602.933 [LoopControl] Loaded 2025-09-23T15:33:22.933Z,1758641602.933 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-09-23T15:33:22.933Z,1758641602.933 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-09-23T15:33:22.935Z,1758641602.935 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-09-23T15:33:22.951Z,1758641602.951 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-09-23T15:33:22.952Z,1758641602.952 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-09-23T15:33:23.174Z,1758641603.174 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-09-23T15:33:23.174Z,1758641603.174 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-09-23T15:33:23.369Z,1758641603.369 [BuoyancyServo] Loaded 2025-09-23T15:33:23.370Z,1758641603.370 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-09-23T15:33:23.393Z,1758641603.393 [ElevatorServo] Loaded 2025-09-23T15:33:23.393Z,1758641603.393 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-09-23T15:33:23.415Z,1758641603.415 [MassServo] Loaded 2025-09-23T15:33:23.415Z,1758641603.415 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-09-23T15:33:23.436Z,1758641603.436 [RudderServo] Loaded 2025-09-23T15:33:23.436Z,1758641603.436 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-09-23T15:33:23.453Z,1758641603.453 [ThrusterHE] Loaded 2025-09-23T15:33:23.454Z,1758641603.454 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-09-23T15:33:23.454Z,1758641603.454 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-09-23T15:33:23.455Z,1758641603.455 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-09-23T15:33:23.598Z,1758641603.598 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-09-23T15:33:23.598Z,1758641603.598 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-09-23T15:33:23.612Z,1758641603.612 [NavChart] Loaded 2025-09-23T15:33:23.613Z,1758641603.613 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-09-23T15:33:23.618Z,1758641603.618 [UniversalFixResidualReporter] Loaded 2025-09-23T15:33:23.619Z,1758641603.619 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-09-23T15:33:23.619Z,1758641603.619 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-09-23T15:33:23.620Z,1758641603.620 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-09-23T15:33:23.710Z,1758641603.710 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-09-23T15:33:23.711Z,1758641603.711 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-09-23T15:33:24.588Z,1758641604.588 [AHRS_M2] Loaded 2025-09-23T15:33:24.588Z,1758641604.588 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-09-23T15:33:25.810Z,1758641605.810 [BPC1] Loaded 2025-09-23T15:33:25.810Z,1758641605.810 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-09-23T15:33:26.021Z,1758641606.021 [DAT] Loaded 2025-09-23T15:33:26.021Z,1758641606.021 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-09-23T15:33:26.022Z,1758641606.022 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4094D4E0 2025-09-23T15:33:26.022Z,1758641606.022 [DAT ThreadHandler](INFO): Protected caller Thread ID is 920 2025-09-23T15:33:26.168Z,1758641606.168 [DataOverHttps] Loaded 2025-09-23T15:33:26.168Z,1758641606.168 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-09-23T15:33:26.169Z,1758641606.169 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097D4E0 2025-09-23T15:33:26.170Z,1758641606.170 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 921 2025-09-23T15:33:26.194Z,1758641606.194 [Depth_Keller] Loaded 2025-09-23T15:33:26.194Z,1758641606.194 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-09-23T15:33:26.200Z,1758641606.200 [DropWeight] Loaded 2025-09-23T15:33:26.200Z,1758641606.200 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-09-23T15:33:26.266Z,1758641606.266 [NAL9602] Loaded 2025-09-23T15:33:26.266Z,1758641606.266 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-09-23T15:33:26.296Z,1758641606.296 [Onboard] Loaded 2025-09-23T15:33:26.297Z,1758641606.297 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-09-23T15:33:26.298Z,1758641606.298 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AD4E0 2025-09-23T15:33:26.298Z,1758641606.298 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922 2025-09-23T15:33:26.313Z,1758641606.313 [Power24vConverter] Loaded 2025-09-23T15:33:26.313Z,1758641606.313 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-09-23T15:33:26.330Z,1758641606.330 [Radio_Surface] Loaded 2025-09-23T15:33:26.330Z,1758641606.330 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-09-23T15:33:26.331Z,1758641606.331 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DD4E0 2025-09-23T15:33:26.332Z,1758641606.332 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923 2025-09-23T15:33:26.347Z,1758641606.347 [Sonardyne_Nano] Loaded 2025-09-23T15:33:26.348Z,1758641606.348 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-09-23T15:33:26.348Z,1758641606.348 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-09-23T15:33:26.349Z,1758641606.349 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-09-23T15:33:26.422Z,1758641606.422 [DepthRateCalculator] Loaded 2025-09-23T15:33:26.422Z,1758641606.422 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-09-23T15:33:26.427Z,1758641606.427 [PitchRateCalculator] Loaded 2025-09-23T15:33:26.427Z,1758641606.427 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-09-23T15:33:26.437Z,1758641606.437 [SpeedCalculator] Loaded 2025-09-23T15:33:26.437Z,1758641606.437 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-09-23T15:33:26.441Z,1758641606.441 [YawRateCalculator] Loaded 2025-09-23T15:33:26.442Z,1758641606.442 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-09-23T15:33:26.462Z,1758641606.462 [ElevatorOffsetCalculator] Loaded 2025-09-23T15:33:26.462Z,1758641606.462 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-09-23T15:33:26.462Z,1758641606.462 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-09-23T15:33:26.463Z,1758641606.463 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-09-23T15:33:26.649Z,1758641606.649 [CANONSampler] Loaded 2025-09-23T15:33:26.649Z,1758641606.649 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2025-09-23T15:33:26.713Z,1758641606.713 [CTD_Seabird] Loaded 2025-09-23T15:33:26.713Z,1758641606.713 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-09-23T15:33:26.714Z,1758641606.714 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A9B4E0 2025-09-23T15:33:26.715Z,1758641606.715 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 924 2025-09-23T15:33:26.738Z,1758641606.738 [PAR_Licor] Loaded 2025-09-23T15:33:26.738Z,1758641606.738 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-09-23T15:33:26.785Z,1758641606.785 [WetLabsBB2FL] Loaded 2025-09-23T15:33:26.785Z,1758641606.785 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-09-23T15:33:26.786Z,1758641606.786 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40ACB4E0 2025-09-23T15:33:26.786Z,1758641606.786 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 925 2025-09-23T15:33:26.787Z,1758641606.787 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-09-23T15:33:26.788Z,1758641606.788 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-09-23T15:33:26.837Z,1758641606.837 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-09-23T15:33:26.837Z,1758641606.837 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-09-23T15:33:27.260Z,1758641607.260 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-09-23T15:33:27.262Z,1758641607.262 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-09-23T15:33:27.464Z,1758641607.464 [SBIT](DEBUG): Construct Startup Built In Test. 2025-09-23T15:33:27.474Z,1758641607.474 [SBIT] Loaded 2025-09-23T15:33:27.474Z,1758641607.474 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-09-23T15:33:27.477Z,1758641607.477 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-09-23T15:33:27.490Z,1758641607.490 [IBIT] Loaded 2025-09-23T15:33:27.491Z,1758641607.491 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-09-23T15:33:27.496Z,1758641607.496 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-09-23T15:33:27.581Z,1758641607.581 [CBIT] Loaded 2025-09-23T15:33:27.581Z,1758641607.581 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-09-23T15:33:27.615Z,1758641607.615 [GFScanner] Loaded 2025-09-23T15:33:27.615Z,1758641607.615 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-09-23T15:33:27.616Z,1758641607.616 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-09-23T15:33:27.616Z,1758641607.616 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-09-23T15:33:27.790Z,1758641607.790 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-09-23T15:33:27.796Z,1758641607.796 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-09-23T15:33:27.799Z,1758641607.799 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-09-23T15:33:27.811Z,1758641607.811 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-09-23T15:33:27.812Z,1758641607.812 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C3D4E0 2025-09-23T15:33:27.813Z,1758641607.813 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 926 2025-09-23T15:33:27.819Z,1758641607.819 [Supervisor](INFO): Main Thread ID is 829 2025-09-23T15:33:27.819Z,1758641607.819 [Supervisor](DEBUG): Running supervisor. 2025-09-23T15:33:27.819Z,1758641607.819 [CommandExec ThreadHandler](INFO): Handler Thread ID is 927 2025-09-23T15:33:27.820Z,1758641607.820 [CommandExec](INFO): Initializing the command executive. 2025-09-23T15:33:27.822Z,1758641607.822 [CommandLine ThreadHandler](INFO): Handler Thread ID is 928 2025-09-23T15:33:27.824Z,1758641607.824 [controlThread ThreadHandler](INFO): Handler Thread ID is 929 2025-09-23T15:33:27.824Z,1758641607.824 [controlThread](DEBUG): Initializing ControlThread 2025-09-23T15:33:27.825Z,1758641607.825 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-09-23T15:33:27.827Z,1758641607.827 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-09-23T15:33:27.827Z,1758641607.827 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-09-23T15:33:27.828Z,1758641607.828 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-09-23T15:33:27.830Z,1758641607.830 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-09-23T15:33:27.830Z,1758641607.830 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-09-23T15:33:27.832Z,1758641607.832 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-09-23T15:33:27.833Z,1758641607.833 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-09-23T15:33:27.833Z,1758641607.833 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-09-23T15:33:27.833Z,1758641607.833 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-09-23T15:33:27.834Z,1758641607.834 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-09-23T15:33:27.837Z,1758641607.837 [SBIT](INFO): Initialize SBIT Component. 2025-09-23T15:33:27.838Z,1758641607.838 [SBIT](IMPORTANT): git: 2025-09-19 2025-09-23T15:33:27.838Z,1758641607.838 [SBIT](INFO): git hash: f5f7d10969816d125effdffd07357c8d50a3a0d0 2025-09-23T15:33:27.838Z,1758641607.838 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-09-23T15:33:27.839Z,1758641607.839 [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-09-23T15:33:27.840Z,1758641607.840 [SBIT](INFO): Beginning SBIT in 80.000000 seconds. 2025-09-23T15:33:27.841Z,1758641607.841 [IBIT](INFO): Initialize IBIT Component. 2025-09-23T15:33:27.842Z,1758641607.842 [CBIT](DEBUG): Initialize CBIT Component. 2025-09-23T15:33:27.843Z,1758641607.843 [logger ThreadHandler](INFO): Handler Thread ID is 930 2025-09-23T15:33:27.853Z,1758641607.853 [CBIT](DEBUG): Initialized mux pins. 2025-09-23T15:33:27.853Z,1758641607.853 [CBIT](DEBUG): Initializing the watchdog timer. 2025-09-23T15:33:27.861Z,1758641607.861 [DAT ThreadHandler](INFO): Handler Thread ID is 931 2025-09-23T15:33:27.862Z,1758641607.862 [DAT](INFO): Powering up 2025-09-23T15:33:27.862Z,1758641607.862 [DAT](DEBUG): Initializing DAT. 2025-09-23T15:33:27.867Z,1758641607.867 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 933 2025-09-23T15:33:27.868Z,1758641607.868 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-09-23T15:33:27.877Z,1758641607.877 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-09-23T15:33:27.878Z,1758641607.878 [CBIT](DEBUG): Initializing heartbeat. 2025-09-23T15:33:27.879Z,1758641607.879 [Onboard ThreadHandler](INFO): Handler Thread ID is 934 2025-09-23T15:33:27.898Z,1758641607.898 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 935 2025-09-23T15:33:27.913Z,1758641607.913 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 936 2025-09-23T15:33:27.914Z,1758641607.914 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-09-23T15:33:27.917Z,1758641607.917 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 938 2025-09-23T15:33:27.922Z,1758641607.922 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 940 2025-09-23T15:33:27.924Z,1758641607.924 [WetLabsBB2FL](INFO): Powering up 2025-09-23T15:33:27.933Z,1758641607.933 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-09-23T15:33:27.933Z,1758641607.933 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-09-23T15:33:27.933Z,1758641607.933 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-09-23T15:33:27.933Z,1758641607.933 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-09-23T15:33:27.934Z,1758641607.934 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-09-23T15:33:27.934Z,1758641607.934 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-09-23T15:33:27.934Z,1758641607.934 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-09-23T15:33:27.934Z,1758641607.934 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-09-23T15:33:27.949Z,1758641607.949 [CBIT](DEBUG): Deactivating emergency mode. 2025-09-23T15:33:27.989Z,1758641607.989 [CBIT](DEBUG): Backplane powered. 2025-09-23T15:33:27.989Z,1758641607.989 [GFScanner](DEBUG): Initializing GFScanner 2025-09-23T15:33:27.989Z,1758641607.989 [GFScanner](DEBUG): Deactivating GF circuits. 2025-09-23T15:33:27.994Z,1758641607.994 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-09-23T15:33:27.995Z,1758641607.995 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-09-23T15:33:27.995Z,1758641607.995 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-09-23T15:33:28.004Z,1758641608.004 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-09-23T15:33:28.071Z,1758641608.071 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-09-23T15:33:28.091Z,1758641608.091 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-09-23T15:33:28.129Z,1758641608.129 [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-09-23T15:33:28.151Z,1758641608.151 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-09-23T15:33:28.151Z,1758641608.151 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-09-23T15:33:28.154Z,1758641608.154 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-09-23T15:33:28.302Z,1758641608.302 [Radio_Surface](INFO): Powering up 2025-09-23T15:33:28.451Z,1758641608.451 [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-09-23T15:33:28.473Z,1758641608.473 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-09-23T15:33:28.475Z,1758641608.475 [Default:A.Wait](DEBUG): Construct Wait. 2025-09-23T15:33:28.493Z,1758641608.493 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-09-23T15:33:28.515Z,1758641608.515 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-09-23T15:33:28.542Z,1758641608.542 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-09-23T15:33:28.557Z,1758641608.557 [Default:E.Execute](DEBUG): Construct Execute. 2025-09-23T15:33:28.560Z,1758641608.560 [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-09-23T15:33:28.569Z,1758641608.569 [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-09-23T15:33:28.589Z,1758641608.589 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-09-23T15:33:28.742Z,1758641608.742 [Depth_Keller](INFO): Initializing. 2025-09-23T15:33:28.743Z,1758641608.743 [Power24vConverter](INFO): Powering up. 2025-09-23T15:33:28.743Z,1758641608.743 [Sonardyne_Nano](INFO): Initializing. 2025-09-23T15:33:28.761Z,1758641608.761 [CANONSampler](INFO): Powering down 2025-09-23T15:33:28.785Z,1758641608.785 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-09-23T15:33:28.812Z,1758641608.812 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-09-23T15:33:28.817Z,1758641608.817 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-09-23T15:33:28.818Z,1758641608.818 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-09-23T15:33:28.825Z,1758641608.825 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-09-23T15:33:28.826Z,1758641608.826 [MassServo](DEBUG): Initializing EZServoServo. 2025-09-23T15:33:28.833Z,1758641608.833 [MassServo](DEBUG): Initializing MassServo. 2025-09-23T15:33:28.834Z,1758641608.834 [RudderServo](DEBUG): Initializing EZServoServo. 2025-09-23T15:33:28.841Z,1758641608.841 [RudderServo](DEBUG): Initializing RudderServo. 2025-09-23T15:33:28.842Z,1758641608.842 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-09-23T15:33:28.849Z,1758641608.849 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-09-23T15:33:30.029Z,1758641610.029 [WetLabsBB2FL](INFO): Powering down 2025-09-23T15:33:31.004Z,1758641611.004 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-09-23T15:33:32.246Z,1758641612.246 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2025-09-23T15:33:34.486Z,1758641614.486 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-09-23T15:33:39.706Z,1758641619.706 [DAT](INFO): DAT read: 2025-09-23T15:33:39.707Z,1758641619.707 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-23T15:33:40.969Z,1758641620.969 [DAT](INFO): DAT read: MF Frequency Band 2025-09-23T15:33:41.219Z,1758641621.219 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-23T15:33:41.219Z,1758641621.219 [DAT](INFO): DAT read: Sep 23 2025 15:33:30 2025-09-23T15:33:42.226Z,1758641622.226 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-23T15:33:42.227Z,1758641622.227 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-09-23T15:33:42.228Z,1758641622.228 [DAT](INFO): commRate: 1200 2025-09-23T15:33:44.293Z,1758641624.293 [DAT](INFO): entering command mode 2025-09-23T15:33:44.494Z,1758641624.494 [DAT](INFO): DAT read: 2025-09-23T15:33:44.494Z,1758641624.494 [DAT](INFO): DAT read: user:1> 2025-09-23T15:33:44.495Z,1758641624.495 [DAT](INFO): setting verbose to 3 2025-09-23T15:33:44.746Z,1758641624.746 [DAT](INFO): DAT read: user:1> 2025-09-23T15:33:44.747Z,1758641624.747 [DAT](INFO): DAT read: Verbose | 3 2025-09-23T15:33:44.747Z,1758641624.747 [DAT](INFO): set verbose to 3 2025-09-23T15:33:44.747Z,1758641624.747 [DAT](INFO): setting DatVerbose to 27440 2025-09-23T15:33:44.998Z,1758641624.998 [DAT](INFO): DAT read: user:2> 2025-09-23T15:33:44.999Z,1758641624.999 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-23T15:33:44.999Z,1758641624.999 [DAT](INFO): set DatVerbose to 27440 2025-09-23T15:33:44.999Z,1758641624.999 [DAT](INFO): setting transmit power to 8 2025-09-23T15:33:45.250Z,1758641625.250 [DAT](INFO): DAT read: user:3> 2025-09-23T15:33:45.251Z,1758641625.251 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-23T15:33:45.251Z,1758641625.251 [DAT](INFO): set transmit power to 8 2025-09-23T15:33:45.251Z,1758641625.251 [DAT](INFO): setting local address to 8 2025-09-23T15:33:45.505Z,1758641625.505 [DAT](INFO): DAT read: user:4> 2025-09-23T15:33:45.507Z,1758641625.507 [DAT](INFO): DAT read: LocalAddr | 8 2025-09-23T15:33:45.507Z,1758641625.507 [DAT](INFO): set local address to 8 2025-09-23T15:33:45.508Z,1758641625.508 [DAT](INFO): Setting time to: 15:33:45 And date to:9/23/2025 2025-09-23T15:33:45.754Z,1758641625.754 [DAT](INFO): DAT read: user:5> 2025-09-23T15:33:45.755Z,1758641625.755 [DAT](INFO): DAT read: Tue Sep 23, 2025 15:33:45 2025-09-23T15:33:45.755Z,1758641625.755 [DAT](INFO): Local DAT time set to Tue Sep 23, 2025 15:33:45 2025-09-23T15:33:56.459Z,1758641636.459 [NAL9602](INFO): Powering up NAL9602 2025-09-23T15:34:07.379Z,1758641647.379 [NAL9602](INFO): NAL9602 initialized 2025-09-23T15:34:37.259Z,1758641677.259 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:34:48.592Z,1758641688.592 [SBIT](IMPORTANT): Beginning Startup BIT 2025-09-23T15:34:48.616Z,1758641688.616 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-09-23T15:34:53.150Z,1758641693.150 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006761 CHAN A1 (24V): 0.000290 CHAN A2 (12V): -0.002362 CHAN A3 (5V): -0.001222 CHAN B0 (3.3V): -0.000218 CHAN B1 (3.15aV): 0.000275 CHAN B2 (3.15bV): -0.000596 CHAN B3 (GND): 0.000038 OPEN: -0.000401 Full Scale: +/- 1 mA 2025-09-23T15:34:57.911Z,1758641697.911 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:35:18.131Z,1758641718.131 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:35:27.890Z,1758641727.890 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-09-23T15:35:38.352Z,1758641738.352 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:35:42.862Z,1758641742.862 [SBIT](IMPORTANT): SBIT PASSED 2025-09-23T15:35:42.862Z,1758641742.862 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-09-23T15:35:42.863Z,1758641742.863 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter; 2025-09-23T15:35:42.863Z,1758641742.863 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter; 2025-09-23T15:35:42.863Z,1758641742.863 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=176.341128 cubic_centimeter; 2025-09-23T15:35:42.863Z,1758641742.863 [SBIT](IMPORTANT): VerticalControl.massDefault=15.055177 millimeter; 2025-09-23T15:35:43.254Z,1758641743.254 [MissionManager](IMPORTANT): Started mission Startup 2025-09-23T15:35:43.255Z,1758641743.255 [Startup] Running Loop=1 2025-09-23T15:35:43.255Z,1758641743.255 [Startup](DEBUG): Aggregate::initialize Startup 2025-09-23T15:35:43.255Z,1758641743.255 [Startup:A.GoToSurface] Running Loop=1 2025-09-23T15:35:43.255Z,1758641743.255 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-09-23T15:35:43.255Z,1758641743.255 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-09-23T15:35:43.256Z,1758641743.256 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-09-23T15:35:43.256Z,1758641743.256 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-09-23T15:35:43.257Z,1758641743.257 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-09-23T15:35:43.257Z,1758641743.257 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-09-23T15:35:43.257Z,1758641743.257 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-09-23T15:35:43.259Z,1758641743.259 [Startup:StartupSatComms] Running Loop=1 2025-09-23T15:35:43.259Z,1758641743.259 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-09-23T15:35:43.259Z,1758641743.259 [Startup:StartupSatComms:A] Running Loop=1 2025-09-23T15:35:43.648Z,1758641743.648 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-09-23T15:35:58.337Z,1758641758.337 [CommandExec](IMPORTANT): got command failComponent 2025-09-23T15:35:58.337Z,1758641758.337 [CommandExec](IMPORTANT): Failed components: 2025-09-23T15:35:58.337Z,1758641758.337 [CommandExec](IMPORTANT): No failed Components. 2025-09-23T15:35:58.954Z,1758641758.954 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:36:19.962Z,1758641779.962 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:36:23.730Z,1758641783.730 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004599 2025-09-23T15:36:28.056Z,1758641788.056 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-09-23T15:36:28.057Z,1758641788.057 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-09-23T15:36:28.094Z,1758641788.094 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-09-23T15:36:28.548Z,1758641788.548 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-09-23T15:36:28.548Z,1758641788.548 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-09-23T15:36:43.458Z,1758641803.458 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-09-23T15:36:43.469Z,1758641803.469 [Startup:StartupSatComms:A](INFO): Timed out from 2025-09-23T15:35:43.3Z 2025-09-23T15:36:43.469Z,1758641803.469 [Startup:StartupSatComms:A] Stopped 2025-09-23T15:36:43.469Z,1758641803.469 [Startup:StartupSatComms:B] Running Loop=1 2025-09-23T15:36:43.830Z,1758641803.830 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-09-23T15:36:51.280Z,1758641811.280 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250923T153106/Courier0000.lzma 2025-09-23T15:36:52.282Z,1758641812.282 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153106/Courier0000.lzma.bak 2025-09-23T15:36:52.282Z,1758641812.282 [DataOverHttps](INFO): SBD MOMSN=26064777 2025-09-23T15:36:56.412Z,1758641816.412 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-09-23T15:37:07.980Z,1758641827.980 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250923T153315/Courier0000.lzma 2025-09-23T15:37:08.982Z,1758641828.982 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0000.lzma.bak 2025-09-23T15:37:08.982Z,1758641828.982 [DataOverHttps](INFO): SBD MOMSN=26064780 2025-09-23T15:37:10.524Z,1758641830.524 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-09-23T15:37:17.674Z,1758641837.674 [CommandExec](IMPORTANT): got command get Onboard.Pressure pound_per_square_inch 2025-09-23T15:37:17.675Z,1758641837.675 [CommandExec](IMPORTANT): Onboard.Pressure 9.494370 psi 2025-09-23T15:37:23.991Z,1758641843.991 [CommandExec](IMPORTANT): got command get Onboard.Humidity 2025-09-23T15:37:23.996Z,1758641843.996 [CommandExec](IMPORTANT): Onboard.Humidity 18.233427 % 2025-09-23T15:37:26.319Z,1758641846.319 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250923T153106/Express0001.lzma 2025-09-23T15:37:27.322Z,1758641847.322 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153106/Express0001.lzma.bak 2025-09-23T15:37:27.322Z,1758641847.322 [DataOverHttps](INFO): SBD MOMSN=26064783 2025-09-23T15:37:32.526Z,1758641852.526 [CommandExec](IMPORTANT): got command show variable nano 2025-09-23T15:37:32.604Z,1758641852.604 [CommandExec](IMPORTANT): NanoDVR.loadControl (none) 2025-09-23T15:37:32.608Z,1758641852.608 [CommandExec](IMPORTANT): NanoDVR.uart (none) 2025-09-23T15:37:32.608Z,1758641852.608 [CommandExec](IMPORTANT): NanoDVR.baud (bit_per_second) 2025-09-23T15:37:32.611Z,1758641852.611 [CommandExec](IMPORTANT): Sonardyne_Nano.loadControl (none) 2025-09-23T15:37:32.611Z,1758641852.611 [CommandExec](IMPORTANT): Sonardyne_Nano.uart (none) 2025-09-23T15:37:32.611Z,1758641852.611 [CommandExec](IMPORTANT): Sonardyne_Nano.baud (bit_per_second) 2025-09-23T15:37:32.663Z,1758641852.663 [CommandExec](IMPORTANT): NanoDVR.loadAtStartup (bool) 2025-09-23T15:37:32.663Z,1758641852.663 [CommandExec](IMPORTANT): NanoDVR.simulateHardware (bool) 2025-09-23T15:37:32.663Z,1758641852.663 [CommandExec](IMPORTANT): NanoDVR.sampleTime (second) 2025-09-23T15:37:32.713Z,1758641852.713 [CommandExec](IMPORTANT): Sonardyne_Nano.loadAtStartup (bool) 2025-09-23T15:37:32.713Z,1758641852.713 [CommandExec](IMPORTANT): Sonardyne_Nano.simulateHardware (bool) 2025-09-23T15:37:32.713Z,1758641852.713 [CommandExec](IMPORTANT): Sonardyne_Nano.chargeMin (percent) 2025-09-23T15:37:32.714Z,1758641852.714 [CommandExec](IMPORTANT): Sonardyne_Nano.chargeMax (percent) 2025-09-23T15:37:32.903Z,1758641852.903 [CommandExec](IMPORTANT): Sonardyne_Nano.enableBroadcast (bool) 2025-09-23T15:37:32.903Z,1758641852.903 [CommandExec](IMPORTANT): Sonardyne_Nano.component_voltage (volt) 2025-09-23T15:37:32.908Z,1758641852.908 [CommandExec](IMPORTANT): Sonardyne_Nano.component_avgVoltage (volt) 2025-09-23T15:37:32.909Z,1758641852.909 [CommandExec](IMPORTANT): Sonardyne_Nano.component_current (milliampere) 2025-09-23T15:37:32.909Z,1758641852.909 [CommandExec](IMPORTANT): Sonardyne_Nano.component_avgCurrent (milliampere) 2025-09-23T15:37:32.909Z,1758641852.909 [CommandExec](IMPORTANT): Sonardyne_Nano.component_discreteIn (bool) 2025-09-23T15:37:32.910Z,1758641852.910 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent (percent) 2025-09-23T15:37:37.991Z,1758641857.991 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-09-23T15:37:43.310Z,1758641863.310 [DataOverHttps](INFO): Sending 869 bytes from file Logs/20250923T153315/Express0001.lzma 2025-09-23T15:37:43.632Z,1758641863.632 [Startup:StartupSatComms:B](INFO): Timed out from 2025-09-23T15:36:43.5Z 2025-09-23T15:37:43.632Z,1758641863.632 [Startup:StartupSatComms:B] Stopped 2025-09-23T15:37:43.652Z,1758641863.652 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-09-23T15:37:43.652Z,1758641863.652 [Startup:StartupSatComms] Stopped 2025-09-23T15:37:43.652Z,1758641863.652 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-09-23T15:37:43.653Z,1758641863.653 [Startup](INFO): Completed Startup 2025-09-23T15:37:43.653Z,1758641863.653 [MissionManager](INFO): Startup is completed. 2025-09-23T15:37:43.653Z,1758641863.653 [MissionManager](INFO): Uninitializing Mission Startup 2025-09-23T15:37:43.653Z,1758641863.653 [Startup] Stopped 2025-09-23T15:37:43.654Z,1758641863.654 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-09-23T15:37:43.654Z,1758641863.654 [Startup:A.GoToSurface] Stopped 2025-09-23T15:37:43.654Z,1758641863.654 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-09-23T15:37:44.034Z,1758641864.034 [MissionManager](IMPORTANT): Started mission Default 2025-09-23T15:37:44.034Z,1758641864.034 [Default] Running Loop=1 2025-09-23T15:37:44.034Z,1758641864.034 [Default](DEBUG): Aggregate::initialize Default 2025-09-23T15:37:44.034Z,1758641864.034 [Default:B.GoToSurface] Running Loop=1 2025-09-23T15:37:44.035Z,1758641864.035 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-09-23T15:37:44.035Z,1758641864.035 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-09-23T15:37:44.035Z,1758641864.035 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-09-23T15:37:44.035Z,1758641864.035 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-09-23T15:37:44.036Z,1758641864.036 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-09-23T15:37:44.036Z,1758641864.036 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-09-23T15:37:44.037Z,1758641864.037 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-09-23T15:37:44.037Z,1758641864.037 [Default:A.Wait] Running Loop=1 2025-09-23T15:37:44.037Z,1758641864.037 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-09-23T15:37:44.310Z,1758641864.310 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0001.lzma.bak 2025-09-23T15:37:44.310Z,1758641864.310 [DataOverHttps](INFO): SBD MOMSN=26064785 2025-09-23T15:37:52.843Z,1758641872.843 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent 2025-09-23T15:37:52.843Z,1758641872.843 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 94.000000 % 2025-09-23T15:37:57.351Z,1758641877.351 [Default:A.Wait](INFO): Done Waiting. 2025-09-23T15:37:57.351Z,1758641877.351 [Default:A.Wait] Stopped 2025-09-23T15:37:57.351Z,1758641877.351 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T15:37:57.774Z,1758641877.774 [Default:CheckIn] Running Loop=1 2025-09-23T15:37:57.774Z,1758641877.774 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T15:37:57.774Z,1758641877.774 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T15:37:58.160Z,1758641878.160 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-09-23T15:39:10.054Z,1758641950.054 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-09-23T15:39:29.066Z,1758641969.066 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-09-23T15:39:29.066Z,1758641969.066 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-09-23T15:39:29.076Z,1758641969.076 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-09-23T15:39:29.482Z,1758641969.482 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-09-23T15:39:29.483Z,1758641969.483 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-09-23T15:40:00.522Z,1758642000.522 [CommandExec](IMPORTANT): got command burn on 2025-09-23T15:40:00.522Z,1758642000.522 [CommandExec](IMPORTANT): Activating dropweight wire 2025-09-23T15:40:04.997Z,1758642004.997 [CommandExec](IMPORTANT): got command burn off 2025-09-23T15:40:04.997Z,1758642004.997 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-09-23T15:40:24.447Z,1758642024.447 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-09-23T15:42:30.057Z,1758642150.057 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-09-23T15:42:30.057Z,1758642150.057 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-09-23T15:42:30.068Z,1758642150.068 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-09-23T15:42:30.473Z,1758642150.473 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-09-23T15:42:30.473Z,1758642150.473 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-09-23T15:42:57.920Z,1758642177.920 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-09-23T15:37:57.8Z 2025-09-23T15:42:57.920Z,1758642177.920 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T15:42:57.920Z,1758642177.920 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T15:42:58.339Z,1758642178.339 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-09-23T15:43:05.383Z,1758642185.383 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250923T153315/Courier0004.lzma 2025-09-23T15:43:06.386Z,1758642186.386 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0004.lzma.bak 2025-09-23T15:43:06.386Z,1758642186.386 [DataOverHttps](INFO): SBD MOMSN=26064821 2025-09-23T15:43:22.074Z,1758642202.074 [DataOverHttps](INFO): Sending 657 bytes from file Logs/20250923T153315/Express0005.lzma 2025-09-23T15:43:23.074Z,1758642203.074 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0005.lzma.bak 2025-09-23T15:43:23.074Z,1758642203.074 [DataOverHttps](INFO): SBD MOMSN=26064823 2025-09-23T15:43:24.195Z,1758642204.195 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T15:43:24.195Z,1758642204.195 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T15:43:24.195Z,1758642204.195 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T15:43:42.357Z,1758642222.357 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-09-23T15:43:47.998Z,1758642227.998 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:44:01.735Z,1758642241.735 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:44:09.418Z,1758642249.418 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-09-23T15:44:09.418Z,1758642249.418 [NAL9602] Data Fault, FailCount= 1 2025-09-23T15:44:09.418Z,1758642249.418 [NAL9602](ERROR): Data Fault 2025-09-23T15:44:09.435Z,1758642249.435 [CBIT](ERROR): Data Fault in component: NAL9602 2025-09-23T15:44:09.819Z,1758642249.819 [NAL9602](INFO): Powering down 2025-09-23T15:44:10.662Z,1758642250.662 [CBIT](INFO): Clearing failed state for component NAL9602 2025-09-23T15:44:10.663Z,1758642250.663 [NAL9602] No Fault, FailCount= 1 2025-09-23T15:44:15.470Z,1758642255.470 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:44:29.207Z,1758642269.207 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:44:40.154Z,1758642280.154 [NAL9602](INFO): Powering up NAL9602 2025-09-23T15:44:43.366Z,1758642283.366 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:44:51.050Z,1758642291.050 [NAL9602](INFO): NAL9602 initialized 2025-09-23T15:44:56.707Z,1758642296.707 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:45:10.434Z,1758642310.434 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:45:24.577Z,1758642324.577 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:45:31.068Z,1758642331.068 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-09-23T15:45:31.068Z,1758642331.068 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-09-23T15:45:31.088Z,1758642331.088 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-09-23T15:45:31.477Z,1758642331.477 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-09-23T15:45:31.477Z,1758642331.477 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-09-23T15:45:38.310Z,1758642338.310 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:45:52.047Z,1758642352.047 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:46:05.378Z,1758642365.378 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:48:24.873Z,1758642504.873 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T15:48:24.873Z,1758642504.873 [Default:CheckIn:C.Wait] Stopped 2025-09-23T15:48:24.874Z,1758642504.874 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T15:48:24.874Z,1758642504.874 [Default:CheckIn:D] Running Loop=1 2025-09-23T15:48:25.215Z,1758642505.215 [Default:CheckIn:D] Stopped 2025-09-23T15:48:25.215Z,1758642505.215 [Default:CheckIn:E] Running Loop=1 2025-09-23T15:48:25.594Z,1758642505.594 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.686336 min 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn:E] Stopped 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn] Stopped 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn](INFO): Running loop #2 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn] Running Loop=2 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T15:48:25.595Z,1758642505.595 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T15:48:32.056Z,1758642512.056 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-09-23T15:48:32.056Z,1758642512.056 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-09-23T15:48:32.101Z,1758642512.101 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-09-23T15:48:32.479Z,1758642512.479 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-09-23T15:48:32.479Z,1758642512.479 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-09-23T15:50:55.926Z,1758642655.926 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155054.00,A,3648.17318,N,12147.28815,W,0.583,83.97,230925,,,A*4A 2025-09-23T15:50:55.930Z,1758642655.930 [NAL9602](INFO): GPS fix at 20250923T155054: (36.802886, -121.788136) 2025-09-23T15:50:55.941Z,1758642655.941 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T15:50:55.941Z,1758642655.941 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T15:51:06.120Z,1758642666.120 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20250923T153315/Courier0007.lzma 2025-09-23T15:51:07.122Z,1758642667.122 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0007.lzma.bak 2025-09-23T15:51:07.122Z,1758642667.122 [DataOverHttps](INFO): SBD MOMSN=26064867 2025-09-23T15:51:23.969Z,1758642683.969 [DataOverHttps](INFO): Sending 405 bytes from file Logs/20250923T153315/Express0008.lzma 2025-09-23T15:51:24.970Z,1758642684.970 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0008.lzma.bak 2025-09-23T15:51:24.970Z,1758642684.970 [DataOverHttps](INFO): SBD MOMSN=26064870 2025-09-23T15:51:26.186Z,1758642686.186 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T15:51:26.186Z,1758642686.186 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T15:51:26.186Z,1758642686.186 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T15:51:28.197Z,1758642688.197 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T15:53:15.649Z,1758642795.649 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-09-23T15:53:21.709Z,1758642801.709 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:53:35.039Z,1758642815.039 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:53:48.779Z,1758642828.779 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:54:02.918Z,1758642842.918 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:54:16.248Z,1758642856.248 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:54:29.984Z,1758642869.984 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:54:43.811Z,1758642883.811 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:54:57.119Z,1758642897.119 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:55:10.857Z,1758642910.857 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:55:23.716Z,1758642923.716 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:55:37.864Z,1758642937.864 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T15:56:26.775Z,1758642986.775 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T15:56:26.775Z,1758642986.775 [Default:CheckIn:C.Wait] Stopped 2025-09-23T15:56:26.776Z,1758642986.776 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T15:56:26.776Z,1758642986.776 [Default:CheckIn:D] Running Loop=1 2025-09-23T15:56:27.169Z,1758642987.169 [Default:CheckIn:D] Stopped 2025-09-23T15:56:27.169Z,1758642987.169 [Default:CheckIn:E] Running Loop=1 2025-09-23T15:56:27.567Z,1758642987.567 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.718909 min 2025-09-23T15:56:27.567Z,1758642987.567 [Default:CheckIn:E] Stopped 2025-09-23T15:56:27.567Z,1758642987.567 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T15:56:27.567Z,1758642987.567 [Default:CheckIn] Stopped 2025-09-23T15:56:27.567Z,1758642987.567 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T15:56:27.567Z,1758642987.567 [Default:CheckIn](INFO): Running loop #3 2025-09-23T15:56:27.567Z,1758642987.567 [Default:CheckIn] Running Loop=3 2025-09-23T15:56:27.568Z,1758642987.568 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T15:56:27.568Z,1758642987.568 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T15:56:29.579Z,1758642989.579 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155628.00,A,3648.16798,N,12147.28007,W,0.505,134.41,230925,,,A*79 2025-09-23T15:56:29.589Z,1758642989.589 [NAL9602](INFO): GPS fix at 20250923T155628: (36.802800, -121.788001) 2025-09-23T15:56:29.600Z,1758642989.600 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T15:56:29.600Z,1758642989.600 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T15:56:37.340Z,1758642997.340 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250923T153315/Courier0010.lzma 2025-09-23T15:56:38.342Z,1758642998.342 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0010.lzma.bak 2025-09-23T15:56:38.342Z,1758642998.342 [DataOverHttps](INFO): SBD MOMSN=26064880 2025-09-23T15:56:54.296Z,1758643014.296 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20250923T153315/Express0011.lzma 2025-09-23T15:56:55.298Z,1758643015.298 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0011.lzma.bak 2025-09-23T15:56:55.298Z,1758643015.298 [DataOverHttps](INFO): SBD MOMSN=26064883 2025-09-23T15:56:56.665Z,1758643016.665 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T15:56:56.665Z,1758643016.665 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T15:56:56.665Z,1758643016.665 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T15:57:52.465Z,1758643072.465 [NAL9602](INFO): SBD MO Status=2, MOMSN=64417, MT Status=2, MTMSN=0 2025-09-23T15:57:52.465Z,1758643072.465 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-23T15:58:00.883Z,1758643080.883 [NAL9602](INFO): SBD MO Status=0, MOMSN=64417, MT Status=0, MTMSN=0 2025-09-23T15:58:00.883Z,1758643080.883 [NAL9602](INFO): No messages in MT queue 2025-09-23T15:58:31.585Z,1758643111.585 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:01:57.234Z,1758643317.234 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:01:57.235Z,1758643317.235 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:01:57.235Z,1758643317.235 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:01:57.235Z,1758643317.235 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:01:57.651Z,1758643317.651 [Default:CheckIn:D] Stopped 2025-09-23T16:01:57.651Z,1758643317.651 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:01:58.056Z,1758643318.056 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.226947 min 2025-09-23T16:01:58.056Z,1758643318.056 [Default:CheckIn:E] Stopped 2025-09-23T16:01:58.056Z,1758643318.056 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:01:58.056Z,1758643318.056 [Default:CheckIn] Stopped 2025-09-23T16:01:58.056Z,1758643318.056 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:01:58.057Z,1758643318.057 [Default:CheckIn](INFO): Running loop #4 2025-09-23T16:01:58.057Z,1758643318.057 [Default:CheckIn] Running Loop=4 2025-09-23T16:01:58.057Z,1758643318.057 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:01:58.057Z,1758643318.057 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:02:00.051Z,1758643320.051 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160159.00,A,3648.15185,N,12147.22575,W,0.039,28.50,230925,,,A*4B 2025-09-23T16:02:00.054Z,1758643320.054 [NAL9602](INFO): GPS fix at 20250923T160159: (36.802531, -121.787096) 2025-09-23T16:02:00.089Z,1758643320.089 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:02:00.089Z,1758643320.089 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:02:07.275Z,1758643327.275 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0013.lzma 2025-09-23T16:02:08.278Z,1758643328.278 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0013.lzma.bak 2025-09-23T16:02:08.278Z,1758643328.278 [DataOverHttps](INFO): SBD MOMSN=26064913 2025-09-23T16:02:16.733Z,1758643336.733 [DataOverHttps](IMPORTANT): SBD MTMSN=20250923T160215 2025-09-23T16:02:17.019Z,1758643337.019 [NAL9602](INFO): SBD MO Status=0, MOMSN=64418, MT Status=0, MTMSN=0 2025-09-23T16:02:17.019Z,1758643337.019 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:02:27.288Z,1758643347.288 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20250923T153315/Express0014.lzma 2025-09-23T16:02:27.291Z,1758643347.291 [DataOverHttps](INFO): Received command: ibit 2025-09-23T16:02:27.369Z,1758643347.369 [CommandExec](IMPORTANT): got command ibit 2025-09-23T16:02:27.650Z,1758643347.650 [IBIT](IMPORTANT): Beginning Initiated BIT 2025-09-23T16:02:27.651Z,1758643347.651 [IBIT](IMPORTANT): Beginning control surface checks. 2025-09-23T16:02:27.654Z,1758643347.654 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-09-23T16:02:28.769Z,1758643348.769 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0014.lzma.bak 2025-09-23T16:02:28.769Z,1758643348.769 [DataOverHttps](IMPORTANT): SBD MOMSN=26064919, MTMSN=20250923T160227 2025-09-23T16:02:29.207Z,1758643349.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160228.00,A,3648.15173,N,12147.22549,W,0.039,28.50,230925,,,A*48 2025-09-23T16:02:29.209Z,1758643349.209 [NAL9602](INFO): GPS fix at 20250923T160228: (36.802529, -121.787092) 2025-09-23T16:02:32.084Z,1758643352.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160231.00,A,3648.15186,N,12147.22549,W,0.078,28.50,230925,,,A*4F 2025-09-23T16:02:32.086Z,1758643352.086 [NAL9602](INFO): GPS fix at 20250923T160231: (36.802531, -121.787092) 2025-09-23T16:02:32.200Z,1758643352.200 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.001285 CHAN A1 (24V): 0.000874 CHAN A2 (12V): -0.002004 CHAN A3 (5V): -0.001745 CHAN B0 (3.3V): 0.000187 CHAN B1 (3.15aV): -0.000285 CHAN B2 (3.15bV): 0.000134 CHAN B3 (GND): -0.000142 OPEN: -0.000208 Full Scale: +/- 1 mA 2025-09-23T16:02:34.899Z,1758643354.899 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160234.00,A,3648.15203,N,12147.22548,W,0.078,28.50,230925,,,A*45 2025-09-23T16:02:34.901Z,1758643354.901 [NAL9602](INFO): GPS fix at 20250923T160234: (36.802534, -121.787091) 2025-09-23T16:02:36.264Z,1758643356.264 [DataOverHttps](INFO): Received command: failc 2025-09-23T16:02:36.345Z,1758643356.345 [CommandExec](IMPORTANT): got command failComponent 2025-09-23T16:02:36.345Z,1758643356.345 [CommandExec](IMPORTANT): Failed components: 2025-09-23T16:02:36.345Z,1758643356.345 [CommandExec](IMPORTANT): No failed Components. 2025-09-23T16:02:37.743Z,1758643357.743 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160237.00,A,3648.15209,N,12147.22543,W,0.058,28.50,230925,,,A*45 2025-09-23T16:02:37.745Z,1758643357.745 [NAL9602](INFO): GPS fix at 20250923T160237: (36.802535, -121.787091) 2025-09-23T16:02:40.959Z,1758643360.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160240.00,A,3648.15227,N,12147.22568,W,0.039,28.50,230925,,,A*47 2025-09-23T16:02:40.961Z,1758643360.961 [NAL9602](INFO): GPS fix at 20250923T160240: (36.802538, -121.787095) 2025-09-23T16:02:43.791Z,1758643363.791 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160243.00,A,3648.15239,N,12147.22586,W,0.156,28.50,230925,,,A*43 2025-09-23T16:02:43.797Z,1758643363.797 [NAL9602](INFO): GPS fix at 20250923T160243: (36.802540, -121.787098) 2025-09-23T16:02:45.031Z,1758643365.031 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250923T153315/Courier0016.lzma 2025-09-23T16:02:46.034Z,1758643366.034 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0016.lzma.bak 2025-09-23T16:02:46.034Z,1758643366.034 [DataOverHttps](INFO): SBD MOMSN=26064925 2025-09-23T16:02:47.016Z,1758643367.016 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160246.00,A,3648.15247,N,12147.22597,W,0.019,28.50,230925,,,A*45 2025-09-23T16:02:47.018Z,1758643367.018 [NAL9602](INFO): GPS fix at 20250923T160246: (36.802541, -121.787099) 2025-09-23T16:02:49.851Z,1758643369.851 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160249.00,A,3648.15254,N,12147.22608,W,0.039,28.50,230925,,,A*4F 2025-09-23T16:02:49.857Z,1758643369.857 [NAL9602](INFO): GPS fix at 20250923T160249: (36.802542, -121.787101) 2025-09-23T16:02:53.079Z,1758643373.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160252.00,A,3648.15247,N,12147.22594,W,0.078,28.50,230925,,,A*44 2025-09-23T16:02:53.081Z,1758643373.081 [NAL9602](INFO): GPS fix at 20250923T160252: (36.802541, -121.787099) 2025-09-23T16:02:55.554Z,1758643375.554 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:02:55.948Z,1758643375.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160255.00,A,3648.15251,N,12147.22619,W,0.000,28.50,230925,,,A*4D 2025-09-23T16:02:55.954Z,1758643375.954 [NAL9602](INFO): GPS fix at 20250923T160255: (36.802542, -121.787103) 2025-09-23T16:02:59.152Z,1758643379.152 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160258.00,A,3648.15244,N,12147.22628,W,0.078,28.50,230925,,,A*49 2025-09-23T16:02:59.188Z,1758643379.188 [NAL9602](INFO): GPS fix at 20250923T160258: (36.802541, -121.787105) 2025-09-23T16:03:01.967Z,1758643381.967 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160301.00,A,3648.15231,N,12147.22629,W,0.097,28.50,230925,,,A*46 2025-09-23T16:03:01.969Z,1758643381.969 [NAL9602](INFO): GPS fix at 20250923T160301: (36.802538, -121.787105) 2025-09-23T16:03:02.805Z,1758643382.805 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0019.lzma 2025-09-23T16:03:03.806Z,1758643383.806 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0019.lzma.bak 2025-09-23T16:03:03.806Z,1758643383.806 [DataOverHttps](INFO): SBD MOMSN=26064927 2025-09-23T16:03:04.799Z,1758643384.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160304.00,A,3648.15223,N,12147.22625,W,0.058,28.50,230925,,,A*4F 2025-09-23T16:03:04.802Z,1758643384.802 [NAL9602](INFO): GPS fix at 20250923T160304: (36.802537, -121.787104) 2025-09-23T16:03:07.719Z,1758643387.719 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:03:08.055Z,1758643388.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160307.00,A,3648.15208,N,12147.22599,W,0.039,28.50,230925,,,A*46 2025-09-23T16:03:08.058Z,1758643388.058 [NAL9602](INFO): GPS fix at 20250923T160307: (36.802535, -121.787100) 2025-09-23T16:03:10.851Z,1758643390.851 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160310.00,A,3648.15196,N,12147.22609,W,0.019,28.50,230925,,,A*4C 2025-09-23T16:03:10.862Z,1758643390.862 [NAL9602](INFO): GPS fix at 20250923T160310: (36.802533, -121.787102) 2025-09-23T16:03:14.083Z,1758643394.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160313.00,A,3648.15176,N,12147.22613,W,0.000,28.50,230925,,,A*42 2025-09-23T16:03:14.085Z,1758643394.085 [NAL9602](INFO): GPS fix at 20250923T160313: (36.802529, -121.787102) 2025-09-23T16:03:14.128Z,1758643394.128 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802528 Longitude: -121.787102 2025-09-23T16:03:14.537Z,1758643394.537 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active. 2025-09-23T16:03:14.910Z,1758643394.910 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2025-09-23T16:03:14.911Z,1758643394.911 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2025-09-23T16:03:14.911Z,1758643394.911 [IBIT](IMPORTANT): Pressure:9.606194 PSI 2025-09-23T16:03:14.911Z,1758643394.911 [IBIT](IMPORTANT): Humidity:18.056404 % 2025-09-23T16:03:15.374Z,1758643395.374 [IBIT](IMPORTANT): Vehicle Pitch:-1.295814 degrees 2025-09-23T16:03:15.374Z,1758643395.374 [IBIT](IMPORTANT): Vehicle Roll:-0.634783 degrees 2025-09-23T16:03:15.374Z,1758643395.374 [IBIT](IMPORTANT): Vehicle Heading:4.882383 degrees 2025-09-23T16:03:15.776Z,1758643395.776 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2025-09-23T16:03:15.800Z,1758643395.800 [IBIT](IMPORTANT): buoyancyNeutral: 176.341125 cc 2025-09-23T16:03:15.800Z,1758643395.800 [IBIT](IMPORTANT): massDefault: 1.505518 cm 2025-09-23T16:03:15.801Z,1758643395.801 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2025-09-23T16:03:15.801Z,1758643395.801 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2025-09-23T16:03:15.801Z,1758643395.801 [IBIT](IMPORTANT): IBIT PASSED 2025-09-23T16:03:19.337Z,1758643399.337 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:03:20.256Z,1758643400.256 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20250923T153315/Express0017.lzma 2025-09-23T16:03:21.258Z,1758643401.258 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0017.lzma.bak 2025-09-23T16:03:21.258Z,1758643401.258 [DataOverHttps](INFO): SBD MOMSN=26064930 2025-09-23T16:03:31.047Z,1758643411.047 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:03:37.237Z,1758643417.237 [DataOverHttps](INFO): Sending 374 bytes from file Logs/20250923T153315/Express0020.lzma 2025-09-23T16:03:38.238Z,1758643418.238 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0020.lzma.bak 2025-09-23T16:03:38.238Z,1758643418.238 [DataOverHttps](INFO): SBD MOMSN=26064937 2025-09-23T16:03:39.551Z,1758643419.551 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:03:39.551Z,1758643419.551 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:03:39.551Z,1758643419.551 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:03:42.765Z,1758643422.765 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:03:46.411Z,1758643426.411 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:03:54.884Z,1758643434.884 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:04:06.196Z,1758643446.196 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:04:18.724Z,1758643458.724 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T16:04:28.837Z,1758643468.837 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 4. 2025-09-23T16:04:28.842Z,1758643468.842 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2025-09-23T16:08:40.166Z,1758643720.166 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:08:40.166Z,1758643720.166 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:08:40.166Z,1758643720.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:08:40.166Z,1758643720.166 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:08:40.578Z,1758643720.578 [Default:CheckIn:D] Stopped 2025-09-23T16:08:40.578Z,1758643720.578 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:08:40.977Z,1758643720.977 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.942395 min 2025-09-23T16:08:40.977Z,1758643720.977 [Default:CheckIn:E] Stopped 2025-09-23T16:08:40.977Z,1758643720.977 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:08:40.977Z,1758643720.977 [Default:CheckIn] Stopped 2025-09-23T16:08:40.977Z,1758643720.977 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:08:40.978Z,1758643720.978 [Default:CheckIn](INFO): Running loop #5 2025-09-23T16:08:40.978Z,1758643720.978 [Default:CheckIn] Running Loop=5 2025-09-23T16:08:40.978Z,1758643720.978 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:08:40.978Z,1758643720.978 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:08:42.987Z,1758643722.987 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160842.00,A,3648.15112,N,12147.22796,W,0.019,28.50,230925,,,D*4E 2025-09-23T16:08:42.990Z,1758643722.990 [NAL9602](INFO): GPS fix at 20250923T160842: (36.802519, -121.787133) 2025-09-23T16:08:43.001Z,1758643723.001 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:08:43.001Z,1758643723.001 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:08:50.140Z,1758643730.140 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250923T153315/Courier0022.lzma 2025-09-23T16:08:51.142Z,1758643731.142 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0022.lzma.bak 2025-09-23T16:08:51.142Z,1758643731.142 [DataOverHttps](INFO): SBD MOMSN=26065001 2025-09-23T16:09:07.050Z,1758643747.050 [DataOverHttps](INFO): Sending 731 bytes from file Logs/20250923T153315/Express0023.lzma 2025-09-23T16:09:08.058Z,1758643748.058 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0023.lzma.bak 2025-09-23T16:09:08.058Z,1758643748.058 [DataOverHttps](INFO): SBD MOMSN=26065004 2025-09-23T16:09:09.259Z,1758643749.259 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:09:09.259Z,1758643749.259 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:09:09.259Z,1758643749.259 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:09:12.075Z,1758643752.075 [NAL9602](INFO): SBD MO Status=2, MOMSN=64419, MT Status=2, MTMSN=0 2025-09-23T16:09:12.075Z,1758643752.075 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-23T16:09:35.103Z,1758643775.103 [NAL9602](INFO): SBD MO Status=2, MOMSN=64419, MT Status=2, MTMSN=0 2025-09-23T16:09:35.103Z,1758643775.103 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-23T16:09:46.815Z,1758643786.815 [NAL9602](INFO): SBD MO Status=0, MOMSN=64419, MT Status=0, MTMSN=0 2025-09-23T16:09:46.816Z,1758643786.816 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:10:17.521Z,1758643817.521 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:14:09.845Z,1758644049.845 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:14:09.845Z,1758644049.845 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:14:09.845Z,1758644049.845 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:14:09.845Z,1758644049.845 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:14:10.249Z,1758644050.249 [Default:CheckIn:D] Stopped 2025-09-23T16:14:10.249Z,1758644050.249 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:14:10.664Z,1758644050.664 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.436906 min 2025-09-23T16:14:10.664Z,1758644050.664 [Default:CheckIn:E] Stopped 2025-09-23T16:14:10.664Z,1758644050.664 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:14:10.664Z,1758644050.664 [Default:CheckIn] Stopped 2025-09-23T16:14:10.665Z,1758644050.665 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:14:10.665Z,1758644050.665 [Default:CheckIn](INFO): Running loop #6 2025-09-23T16:14:10.665Z,1758644050.665 [Default:CheckIn] Running Loop=6 2025-09-23T16:14:10.665Z,1758644050.665 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:14:10.665Z,1758644050.665 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:14:12.667Z,1758644052.667 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161411.00,A,3648.15346,N,12147.22596,W,0.019,28.50,230925,,,D*44 2025-09-23T16:14:12.669Z,1758644052.669 [NAL9602](INFO): GPS fix at 20250923T161411: (36.802558, -121.787099) 2025-09-23T16:14:12.700Z,1758644052.700 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:14:12.700Z,1758644052.700 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:14:22.844Z,1758644062.844 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0025.lzma 2025-09-23T16:14:23.846Z,1758644063.846 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0025.lzma.bak 2025-09-23T16:14:23.846Z,1758644063.846 [DataOverHttps](INFO): SBD MOMSN=26065044 2025-09-23T16:14:40.532Z,1758644080.532 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250923T153315/Express0026.lzma 2025-09-23T16:14:41.534Z,1758644081.534 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0026.lzma.bak 2025-09-23T16:14:41.534Z,1758644081.534 [DataOverHttps](INFO): SBD MOMSN=26065047 2025-09-23T16:14:42.604Z,1758644082.604 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:14:42.604Z,1758644082.604 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:14:42.604Z,1758644082.604 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:14:47.049Z,1758644087.049 [NAL9602](INFO): SBD MO Status=2, MOMSN=64420, MT Status=2, MTMSN=0 2025-09-23T16:14:47.050Z,1758644087.050 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-23T16:15:06.031Z,1758644106.031 [NAL9602](INFO): SBD MO Status=2, MOMSN=64420, MT Status=2, MTMSN=0 2025-09-23T16:15:06.031Z,1758644106.031 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-23T16:15:15.347Z,1758644115.347 [NAL9602](INFO): SBD MO Status=0, MOMSN=64420, MT Status=0, MTMSN=0 2025-09-23T16:15:15.347Z,1758644115.347 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:15:46.025Z,1758644146.025 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:19:43.291Z,1758644383.291 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:19:43.291Z,1758644383.291 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:19:43.291Z,1758644383.291 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:19:43.291Z,1758644383.291 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:19:43.697Z,1758644383.697 [Default:CheckIn:D] Stopped 2025-09-23T16:19:43.697Z,1758644383.697 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.994377 min 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn:E] Stopped 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn] Stopped 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn](INFO): Running loop #7 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn] Running Loop=7 2025-09-23T16:19:44.113Z,1758644384.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:19:44.114Z,1758644384.114 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:19:46.111Z,1758644386.111 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161945.00,A,3648.15275,N,12147.22926,W,0.019,28.50,230925,,,D*4E 2025-09-23T16:19:46.114Z,1758644386.114 [NAL9602](INFO): GPS fix at 20250923T161945: (36.802546, -121.787154) 2025-09-23T16:19:46.125Z,1758644386.125 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:19:46.125Z,1758644386.125 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:19:53.375Z,1758644393.375 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0028.lzma 2025-09-23T16:19:54.378Z,1758644394.378 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0028.lzma.bak 2025-09-23T16:19:54.378Z,1758644394.378 [DataOverHttps](INFO): SBD MOMSN=26065076 2025-09-23T16:20:02.272Z,1758644402.272 [NAL9602](INFO): SBD MO Status=2, MOMSN=64421, MT Status=2, MTMSN=0 2025-09-23T16:20:02.272Z,1758644402.272 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-23T16:20:10.412Z,1758644410.412 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250923T153315/Express0029.lzma 2025-09-23T16:20:11.414Z,1758644411.414 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0029.lzma.bak 2025-09-23T16:20:11.414Z,1758644411.414 [DataOverHttps](INFO): SBD MOMSN=26065079 2025-09-23T16:20:11.967Z,1758644411.967 [NAL9602](INFO): SBD MO Status=0, MOMSN=64421, MT Status=0, MTMSN=0 2025-09-23T16:20:11.967Z,1758644411.967 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:20:12.796Z,1758644412.796 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:20:12.796Z,1758644412.796 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:20:12.796Z,1758644412.796 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:20:42.678Z,1758644442.678 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:25:13.497Z,1758644713.497 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:25:13.497Z,1758644713.497 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:25:13.497Z,1758644713.497 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:25:13.497Z,1758644713.497 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:25:13.906Z,1758644713.906 [Default:CheckIn:D] Stopped 2025-09-23T16:25:13.906Z,1758644713.906 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:25:14.295Z,1758644714.295 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.497856 min 2025-09-23T16:25:14.295Z,1758644714.295 [Default:CheckIn:E] Stopped 2025-09-23T16:25:14.296Z,1758644714.296 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:25:14.296Z,1758644714.296 [Default:CheckIn] Stopped 2025-09-23T16:25:14.296Z,1758644714.296 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:25:14.296Z,1758644714.296 [Default:CheckIn](INFO): Running loop #8 2025-09-23T16:25:14.296Z,1758644714.296 [Default:CheckIn] Running Loop=8 2025-09-23T16:25:14.297Z,1758644714.297 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:25:14.297Z,1758644714.297 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:25:16.305Z,1758644716.305 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162515.00,A,3648.15105,N,12147.22835,W,0.058,28.50,230925,,,D*46 2025-09-23T16:25:16.308Z,1758644716.308 [NAL9602](INFO): GPS fix at 20250923T162515: (36.802518, -121.787139) 2025-09-23T16:25:16.319Z,1758644716.319 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:25:16.319Z,1758644716.319 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:25:23.792Z,1758644723.792 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0031.lzma 2025-09-23T16:25:24.794Z,1758644724.794 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0031.lzma.bak 2025-09-23T16:25:24.794Z,1758644724.794 [DataOverHttps](INFO): SBD MOMSN=26065120 2025-09-23T16:25:40.708Z,1758644740.708 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250923T153315/Express0032.lzma 2025-09-23T16:25:41.710Z,1758644741.710 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0032.lzma.bak 2025-09-23T16:25:41.710Z,1758644741.710 [DataOverHttps](INFO): SBD MOMSN=26065123 2025-09-23T16:25:42.977Z,1758644742.977 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:25:42.977Z,1758644742.977 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:25:42.977Z,1758644742.977 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:25:51.059Z,1758644751.059 [NAL9602](INFO): SBD MO Status=0, MOMSN=64422, MT Status=0, MTMSN=0 2025-09-23T16:25:51.059Z,1758644751.059 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:26:21.764Z,1758644781.764 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:30:43.713Z,1758645043.713 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:30:43.714Z,1758645043.714 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:30:43.714Z,1758645043.714 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:30:43.714Z,1758645043.714 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:30:44.091Z,1758645044.091 [Default:CheckIn:D] Stopped 2025-09-23T16:30:44.091Z,1758645044.091 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:30:44.497Z,1758645044.497 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.000948 min 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn:E] Stopped 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn] Stopped 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn](INFO): Running loop #9 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn] Running Loop=9 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:30:44.498Z,1758645044.498 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:30:46.511Z,1758645046.511 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163045.00,A,3648.15142,N,12147.22812,W,0.019,28.50,230925,,,D*44 2025-09-23T16:30:46.522Z,1758645046.522 [NAL9602](INFO): GPS fix at 20250923T163045: (36.802524, -121.787135) 2025-09-23T16:30:46.533Z,1758645046.533 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:30:46.533Z,1758645046.533 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:30:54.448Z,1758645054.448 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0034.lzma 2025-09-23T16:30:55.450Z,1758645055.450 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0034.lzma.bak 2025-09-23T16:30:55.450Z,1758645055.450 [DataOverHttps](INFO): SBD MOMSN=26065148 2025-09-23T16:31:11.464Z,1758645071.464 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20250923T153315/Express0035.lzma 2025-09-23T16:31:12.466Z,1758645072.466 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0035.lzma.bak 2025-09-23T16:31:12.466Z,1758645072.466 [DataOverHttps](INFO): SBD MOMSN=26065190 2025-09-23T16:31:13.585Z,1758645073.585 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:31:13.585Z,1758645073.585 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:31:13.585Z,1758645073.585 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:31:13.981Z,1758645073.981 [NAL9602](INFO): SBD MO Status=2, MOMSN=64423, MT Status=2, MTMSN=0 2025-09-23T16:31:13.981Z,1758645073.981 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-23T16:31:24.083Z,1758645084.083 [NAL9602](INFO): SBD MO Status=0, MOMSN=64423, MT Status=0, MTMSN=0 2025-09-23T16:31:24.083Z,1758645084.083 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:31:54.781Z,1758645114.781 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:36:14.287Z,1758645374.287 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:36:14.288Z,1758645374.288 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:36:14.288Z,1758645374.288 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:36:14.288Z,1758645374.288 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:36:14.699Z,1758645374.699 [Default:CheckIn:D] Stopped 2025-09-23T16:36:14.699Z,1758645374.699 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:36:15.097Z,1758645375.097 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.511084 min 2025-09-23T16:36:15.097Z,1758645375.097 [Default:CheckIn:E] Stopped 2025-09-23T16:36:15.098Z,1758645375.098 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:36:15.098Z,1758645375.098 [Default:CheckIn] Stopped 2025-09-23T16:36:15.098Z,1758645375.098 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:36:15.098Z,1758645375.098 [Default:CheckIn](INFO): Running loop #10 2025-09-23T16:36:15.098Z,1758645375.098 [Default:CheckIn] Running Loop=10 2025-09-23T16:36:15.098Z,1758645375.098 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:36:15.098Z,1758645375.098 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:36:17.107Z,1758645377.107 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163616.00,A,3648.14924,N,12147.22577,W,0.019,28.50,230925,,,D*43 2025-09-23T16:36:17.110Z,1758645377.110 [NAL9602](INFO): GPS fix at 20250923T163616: (36.802487, -121.787096) 2025-09-23T16:36:17.125Z,1758645377.125 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:36:17.125Z,1758645377.125 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:36:27.452Z,1758645387.452 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250923T153315/Courier0037.lzma 2025-09-23T16:36:28.454Z,1758645388.454 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0037.lzma.bak 2025-09-23T16:36:28.454Z,1758645388.454 [DataOverHttps](INFO): SBD MOMSN=26065196 2025-09-23T16:36:44.316Z,1758645404.316 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250923T153315/Express0038.lzma 2025-09-23T16:36:45.318Z,1758645405.318 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0038.lzma.bak 2025-09-23T16:36:45.318Z,1758645405.318 [DataOverHttps](INFO): SBD MOMSN=26065199 2025-09-23T16:36:46.331Z,1758645406.331 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:36:46.331Z,1758645406.331 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:36:46.331Z,1758645406.331 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:36:53.988Z,1758645413.988 [NAL9602](INFO): SBD MO Status=0, MOMSN=64424, MT Status=0, MTMSN=0 2025-09-23T16:36:53.988Z,1758645413.988 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:37:24.690Z,1758645444.690 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:41:47.019Z,1758645707.019 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:41:47.019Z,1758645707.019 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:41:47.019Z,1758645707.019 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:41:47.020Z,1758645707.020 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:41:47.411Z,1758645707.411 [Default:CheckIn:D] Stopped 2025-09-23T16:41:47.411Z,1758645707.411 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:41:47.825Z,1758645707.825 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.056283 min 2025-09-23T16:41:47.825Z,1758645707.825 [Default:CheckIn:E] Stopped 2025-09-23T16:41:47.825Z,1758645707.825 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:41:47.825Z,1758645707.825 [Default:CheckIn] Stopped 2025-09-23T16:41:47.826Z,1758645707.826 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:41:47.826Z,1758645707.826 [Default:CheckIn](INFO): Running loop #11 2025-09-23T16:41:47.826Z,1758645707.826 [Default:CheckIn] Running Loop=11 2025-09-23T16:41:47.826Z,1758645707.826 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:41:47.826Z,1758645707.826 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:41:49.831Z,1758645709.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164149.00,A,3648.15330,N,12147.22385,W,0.058,33.13,230925,,,D*44 2025-09-23T16:41:49.833Z,1758645709.833 [NAL9602](INFO): GPS fix at 20250923T164149: (36.802555, -121.787064) 2025-09-23T16:41:49.845Z,1758645709.845 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:41:49.845Z,1758645709.845 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:41:57.840Z,1758645717.840 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0040.lzma 2025-09-23T16:41:58.842Z,1758645718.842 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0040.lzma.bak 2025-09-23T16:41:58.842Z,1758645718.842 [DataOverHttps](INFO): SBD MOMSN=26065224 2025-09-23T16:42:13.659Z,1758645733.659 [NAL9602](INFO): SBD MO Status=0, MOMSN=64425, MT Status=0, MTMSN=0 2025-09-23T16:42:13.659Z,1758645733.659 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:42:14.892Z,1758645734.892 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20250923T153315/Express0041.lzma 2025-09-23T16:42:15.894Z,1758645735.894 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0041.lzma.bak 2025-09-23T16:42:15.894Z,1758645735.894 [DataOverHttps](INFO): SBD MOMSN=26065227 2025-09-23T16:42:16.921Z,1758645736.921 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:42:16.921Z,1758645736.921 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:42:16.921Z,1758645736.921 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:42:44.411Z,1758645764.411 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:47:17.619Z,1758646037.619 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:47:17.619Z,1758646037.619 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:47:17.620Z,1758646037.620 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:47:17.620Z,1758646037.620 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:47:18.027Z,1758646038.027 [Default:CheckIn:D] Stopped 2025-09-23T16:47:18.027Z,1758646038.027 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:47:18.431Z,1758646038.431 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.566553 min 2025-09-23T16:47:18.432Z,1758646038.432 [Default:CheckIn:E] Stopped 2025-09-23T16:47:18.432Z,1758646038.432 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:47:18.432Z,1758646038.432 [Default:CheckIn] Stopped 2025-09-23T16:47:18.432Z,1758646038.432 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:47:18.432Z,1758646038.432 [Default:CheckIn](INFO): Running loop #12 2025-09-23T16:47:18.432Z,1758646038.432 [Default:CheckIn] Running Loop=12 2025-09-23T16:47:18.432Z,1758646038.432 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:47:18.433Z,1758646038.433 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:47:20.445Z,1758646040.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164719.00,A,3648.15199,N,12147.21935,W,0.019,58.35,230925,,,D*48 2025-09-23T16:47:20.448Z,1758646040.448 [NAL9602](INFO): GPS fix at 20250923T164719: (36.802533, -121.786989) 2025-09-23T16:47:20.459Z,1758646040.459 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:47:20.459Z,1758646040.459 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:47:28.120Z,1758646048.120 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0043.lzma 2025-09-23T16:47:29.122Z,1758646049.122 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0043.lzma.bak 2025-09-23T16:47:29.122Z,1758646049.122 [DataOverHttps](INFO): SBD MOMSN=26065238 2025-09-23T16:47:33.787Z,1758646053.787 [NAL9602](INFO): SBD MO Status=0, MOMSN=64426, MT Status=0, MTMSN=0 2025-09-23T16:47:33.787Z,1758646053.787 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:47:45.152Z,1758646065.152 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250923T153315/Express0044.lzma 2025-09-23T16:47:46.154Z,1758646066.154 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0044.lzma.bak 2025-09-23T16:47:46.154Z,1758646066.154 [DataOverHttps](INFO): SBD MOMSN=26065241 2025-09-23T16:47:47.531Z,1758646067.531 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:47:47.531Z,1758646067.531 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:47:47.531Z,1758646067.531 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:48:04.489Z,1758646084.489 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:52:48.229Z,1758646368.229 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:52:48.229Z,1758646368.229 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:52:48.229Z,1758646368.229 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:52:48.229Z,1758646368.229 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:52:48.641Z,1758646368.641 [Default:CheckIn:D] Stopped 2025-09-23T16:52:48.641Z,1758646368.641 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:52:49.040Z,1758646369.040 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.076774 min 2025-09-23T16:52:49.040Z,1758646369.040 [Default:CheckIn:E] Stopped 2025-09-23T16:52:49.052Z,1758646369.052 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:52:49.052Z,1758646369.052 [Default:CheckIn] Stopped 2025-09-23T16:52:49.052Z,1758646369.052 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:52:49.052Z,1758646369.052 [Default:CheckIn](INFO): Running loop #13 2025-09-23T16:52:49.053Z,1758646369.053 [Default:CheckIn] Running Loop=13 2025-09-23T16:52:49.053Z,1758646369.053 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:52:49.053Z,1758646369.053 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:52:51.055Z,1758646371.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165250.00,A,3648.41526,N,12147.10710,W,5.559,2.73,230925,,,A*77 2025-09-23T16:52:51.058Z,1758646371.058 [NAL9602](INFO): GPS fix at 20250923T165250: (36.806921, -121.785118) 2025-09-23T16:52:51.069Z,1758646371.069 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:52:51.069Z,1758646371.069 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:52:59.116Z,1758646379.116 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250923T153315/Courier0046.lzma 2025-09-23T16:53:00.118Z,1758646380.118 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0046.lzma.bak 2025-09-23T16:53:00.118Z,1758646380.118 [DataOverHttps](INFO): SBD MOMSN=26065263 2025-09-23T16:53:16.180Z,1758646396.180 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20250923T153315/Express0047.lzma 2025-09-23T16:53:17.182Z,1758646397.182 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0047.lzma.bak 2025-09-23T16:53:17.182Z,1758646397.182 [DataOverHttps](INFO): SBD MOMSN=26065266 2025-09-23T16:53:18.531Z,1758646398.531 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:53:18.531Z,1758646398.531 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:53:18.531Z,1758646398.531 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:53:53.263Z,1758646433.263 [NAL9602](INFO): SBD MO Status=0, MOMSN=64427, MT Status=0, MTMSN=0 2025-09-23T16:53:53.263Z,1758646433.263 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:54:23.998Z,1758646463.998 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T16:58:19.161Z,1758646699.161 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T16:58:19.161Z,1758646699.161 [Default:CheckIn:C.Wait] Stopped 2025-09-23T16:58:19.161Z,1758646699.161 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T16:58:19.161Z,1758646699.161 [Default:CheckIn:D] Running Loop=1 2025-09-23T16:58:19.588Z,1758646699.588 [Default:CheckIn:D] Stopped 2025-09-23T16:58:19.588Z,1758646699.588 [Default:CheckIn:E] Running Loop=1 2025-09-23T16:58:19.984Z,1758646699.984 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.592358 min 2025-09-23T16:58:19.984Z,1758646699.984 [Default:CheckIn:E] Stopped 2025-09-23T16:58:19.992Z,1758646699.992 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T16:58:19.992Z,1758646699.992 [Default:CheckIn] Stopped 2025-09-23T16:58:19.993Z,1758646699.993 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T16:58:19.993Z,1758646699.993 [Default:CheckIn](INFO): Running loop #14 2025-09-23T16:58:19.993Z,1758646699.993 [Default:CheckIn] Running Loop=14 2025-09-23T16:58:19.993Z,1758646699.993 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T16:58:19.993Z,1758646699.993 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T16:58:21.973Z,1758646701.973 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165821.00,A,3648.45017,N,12148.22720,W,19.477,269.66,230925,,,D*4B 2025-09-23T16:58:21.975Z,1758646701.975 [NAL9602](INFO): GPS fix at 20250923T165821: (36.807503, -121.803787) 2025-09-23T16:58:21.995Z,1758646701.995 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T16:58:21.995Z,1758646701.995 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T16:58:30.240Z,1758646710.240 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0049.lzma 2025-09-23T16:58:31.242Z,1758646711.242 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0049.lzma.bak 2025-09-23T16:58:31.242Z,1758646711.242 [DataOverHttps](INFO): SBD MOMSN=26065277 2025-09-23T16:58:36.968Z,1758646716.968 [NAL9602](INFO): SBD MO Status=0, MOMSN=64428, MT Status=0, MTMSN=0 2025-09-23T16:58:36.968Z,1758646716.968 [NAL9602](INFO): No messages in MT queue 2025-09-23T16:58:48.240Z,1758646728.240 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250923T153315/Express0050.lzma 2025-09-23T16:58:50.246Z,1758646730.246 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0050.lzma.bak 2025-09-23T16:58:50.246Z,1758646730.246 [DataOverHttps](INFO): SBD MOMSN=26065280 2025-09-23T16:58:51.535Z,1758646731.535 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T16:58:51.535Z,1758646731.535 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T16:58:51.536Z,1758646731.536 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T16:59:07.678Z,1758646747.678 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T17:00:53.208Z,1758646853.208 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-23T17:01:24.333Z,1758646884.333 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-23T17:03:52.116Z,1758647032.116 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T17:03:52.116Z,1758647032.116 [Default:CheckIn:C.Wait] Stopped 2025-09-23T17:03:52.116Z,1758647032.116 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T17:03:52.116Z,1758647032.116 [Default:CheckIn:D] Running Loop=1 2025-09-23T17:03:52.527Z,1758647032.527 [Default:CheckIn:D] Stopped 2025-09-23T17:03:52.527Z,1758647032.527 [Default:CheckIn:E] Running Loop=1 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.141545 min 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn:E] Stopped 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn] Stopped 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn](INFO): Running loop #15 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn] Running Loop=15 2025-09-23T17:03:52.913Z,1758647032.913 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T17:03:52.914Z,1758647032.914 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T17:03:54.927Z,1758647034.927 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170354.00,A,3647.73085,N,12150.86067,W,24.026,253.23,230925,,,D*42 2025-09-23T17:03:54.938Z,1758647034.938 [NAL9602](INFO): GPS fix at 20250923T170354: (36.795514, -121.847678) 2025-09-23T17:03:54.949Z,1758647034.949 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T17:03:54.949Z,1758647034.949 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T17:04:02.340Z,1758647042.340 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0052.lzma 2025-09-23T17:04:03.342Z,1758647043.342 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0052.lzma.bak 2025-09-23T17:04:03.342Z,1758647043.342 [DataOverHttps](INFO): SBD MOMSN=26065303 2025-09-23T17:04:14.719Z,1758647054.719 [NAL9602](INFO): SBD MO Status=0, MOMSN=64429, MT Status=0, MTMSN=0 2025-09-23T17:04:14.719Z,1758647054.719 [NAL9602](INFO): No messages in MT queue 2025-09-23T17:04:20.778Z,1758647060.778 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250923T153315/Express0053.lzma 2025-09-23T17:04:21.774Z,1758647061.774 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Express0053.lzma.bak 2025-09-23T17:04:21.774Z,1758647061.774 [DataOverHttps](INFO): SBD MOMSN=26065306 2025-09-23T17:04:22.841Z,1758647062.841 [Default:CheckIn:Read_Iridium] Stopped 2025-09-23T17:04:22.841Z,1758647062.841 [Default:CheckIn:C.Wait] Running Loop=1 2025-09-23T17:04:22.841Z,1758647062.841 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-23T17:04:45.469Z,1758647085.469 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-23T17:05:34.748Z,1758647134.748 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:05:46.868Z,1758647146.868 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:05:58.988Z,1758647158.988 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:06:10.704Z,1758647170.704 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:06:22.829Z,1758647182.829 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:06:35.351Z,1758647195.351 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:06:47.068Z,1758647207.068 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:09:23.493Z,1758647363.493 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-09-23T17:09:23.493Z,1758647363.493 [Default:CheckIn:C.Wait] Stopped 2025-09-23T17:09:23.494Z,1758647363.494 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-23T17:09:23.494Z,1758647363.494 [Default:CheckIn:D] Running Loop=1 2025-09-23T17:09:23.848Z,1758647363.848 [Default:CheckIn:D] Stopped 2025-09-23T17:09:23.848Z,1758647363.848 [Default:CheckIn:E] Running Loop=1 2025-09-23T17:09:24.268Z,1758647364.268 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.663558 min 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn:E] Stopped 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn] Stopped 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn](INFO): Running loop #16 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn] Running Loop=16 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-09-23T17:09:24.269Z,1758647364.269 [Default:CheckIn:Read_GPS] Running Loop=1 2025-09-23T17:09:26.249Z,1758647366.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170925.00,A,3647.70161,N,12150.94509,W,0.272,245.41,230925,,,D*7E 2025-09-23T17:09:26.251Z,1758647366.251 [NAL9602](INFO): GPS fix at 20250923T170925: (36.795027, -121.849085) 2025-09-23T17:09:26.263Z,1758647366.263 [Default:CheckIn:Read_GPS] Stopped 2025-09-23T17:09:26.263Z,1758647366.263 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-09-23T17:09:28.264Z,1758647368.264 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:09:35.143Z,1758647375.143 [NAL9602](INFO): SBD MO Status=0, MOMSN=64430, MT Status=0, MTMSN=0 2025-09-23T17:09:35.143Z,1758647375.143 [NAL9602](INFO): No messages in MT queue 2025-09-23T17:09:41.597Z,1758647381.597 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-09-23T17:09:46.648Z,1758647386.648 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250923T153315/Courier0055.lzma 2025-09-23T17:09:47.650Z,1758647387.650 [DataOverHttps](INFO): Moved sent file to Logs/20250923T153315/Courier0055.lzma.bak 2025-09-23T17:09:47.650Z,1758647387.650 [DataOverHttps](IMPORTANT): SBD MOMSN=26065329, MTMSN=20250923T170946 2025-09-23T17:09:55.041Z,1758647395.041 [DataOverHttps](INFO): Received command: restart logs