2025-10-08T15:32:17.688Z,1759937537.688 [Supervisor](DEBUG): Initializing supervisor. 2025-10-08T15:32:17.693Z,1759937537.693 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-10-08T15:32:17.693Z,1759937537.693 [SyncHandler](INFO): Protected caller Thread ID is 836 2025-10-08T15:32:17.694Z,1759937537.694 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-10-08T15:32:17.695Z,1759937537.695 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-10-08T15:32:17.695Z,1759937537.695 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837 2025-10-08T15:32:17.699Z,1759937537.699 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-10-08T15:32:17.720Z,1759937537.720 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-10-08T15:32:17.721Z,1759937537.721 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-10-08T15:32:17.721Z,1759937537.721 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838 2025-10-08T15:32:17.726Z,1759937537.726 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-10-08T15:32:17.727Z,1759937537.727 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-10-08T15:32:17.727Z,1759937537.727 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839 2025-10-08T15:32:17.730Z,1759937537.730 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-10-08T15:32:17.731Z,1759937537.731 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-10-08T15:32:17.731Z,1759937537.731 [logger ThreadHandler](INFO): Protected caller Thread ID is 840 2025-10-08T15:32:17.735Z,1759937537.735 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-10-08T15:32:17.735Z,1759937537.735 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-10-08T15:32:17.739Z,1759937537.739 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-10-08T15:32:18.023Z,1759937538.023 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-10-08T15:32:18.025Z,1759937538.025 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-10-08T15:32:18.127Z,1759937538.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-10-08T15:32:18.128Z,1759937538.128 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-10-08T15:32:18.687Z,1759937538.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-10-08T15:32:18.688Z,1759937538.688 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-10-08T15:32:19.155Z,1759937539.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-10-08T15:32:19.157Z,1759937539.157 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-10-08T15:32:19.266Z,1759937539.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-10-08T15:32:19.267Z,1759937539.267 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-10-08T15:32:19.726Z,1759937539.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-10-08T15:32:19.728Z,1759937539.728 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-10-08T15:32:19.975Z,1759937539.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-10-08T15:32:19.977Z,1759937539.977 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-10-08T15:32:20.804Z,1759937540.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-10-08T15:32:20.806Z,1759937540.806 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-10-08T15:32:20.960Z,1759937540.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-10-08T15:32:20.962Z,1759937540.962 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-10-08T15:32:21.055Z,1759937541.055 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-10-08T15:32:21.966Z,1759937541.966 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-10-08T15:32:21.967Z,1759937541.967 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-10-08T15:32:22.382Z,1759937542.382 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-10-08T15:32:22.382Z,1759937542.382 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-10-08T15:32:22.586Z,1759937542.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-10-08T15:32:22.588Z,1759937542.588 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-10-08T15:32:22.715Z,1759937542.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-10-08T15:32:22.716Z,1759937542.716 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-10-08T15:32:22.966Z,1759937542.966 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-10-08T15:32:22.967Z,1759937542.967 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-10-08T15:32:23.245Z,1759937543.245 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-10-08T15:32:23.247Z,1759937543.247 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2025-10-08T15:32:23.250Z,1759937543.250 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2025-10-08T15:32:23.349Z,1759937543.349 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2025-10-08T15:32:23.465Z,1759937543.465 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2025-10-08T15:32:23.561Z,1759937543.561 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2025-10-08T15:32:23.677Z,1759937543.677 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2025-10-08T15:32:23.786Z,1759937543.786 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2025-10-08T15:32:23.921Z,1759937543.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2025-10-08T15:32:24.089Z,1759937544.089 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2025-10-08T15:32:24.252Z,1759937544.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2025-10-08T15:32:24.377Z,1759937544.377 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2025-10-08T15:32:24.665Z,1759937544.665 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-10-08T15:32:24.667Z,1759937544.667 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2025-10-08T15:32:24.667Z,1759937544.667 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-10-08T15:32:24.680Z,1759937544.680 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-10-08T15:32:24.757Z,1759937544.757 [VerticalControl](DEBUG): Construct VerticalControl. 2025-10-08T15:32:24.823Z,1759937544.823 [VerticalControl] Loaded 2025-10-08T15:32:24.823Z,1759937544.823 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-10-08T15:32:24.826Z,1759937544.826 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-10-08T15:32:24.877Z,1759937544.877 [HorizontalControl] Loaded 2025-10-08T15:32:24.877Z,1759937544.877 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-10-08T15:32:24.879Z,1759937544.879 [SpeedControl](DEBUG): Construct SpeedControl. 2025-10-08T15:32:24.883Z,1759937544.883 [SpeedControl] Loaded 2025-10-08T15:32:24.883Z,1759937544.883 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-10-08T15:32:24.886Z,1759937544.886 [LoopControl](DEBUG): Construct LoopControl. 2025-10-08T15:32:24.886Z,1759937544.886 [LoopControl] Loaded 2025-10-08T15:32:24.887Z,1759937544.887 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-10-08T15:32:24.887Z,1759937544.887 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-10-08T15:32:24.889Z,1759937544.889 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-10-08T15:32:24.905Z,1759937544.905 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-10-08T15:32:24.906Z,1759937544.906 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-10-08T15:32:25.138Z,1759937545.138 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-10-08T15:32:25.138Z,1759937545.138 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-10-08T15:32:25.337Z,1759937545.337 [BuoyancyServo] Loaded 2025-10-08T15:32:25.337Z,1759937545.337 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-10-08T15:32:25.361Z,1759937545.361 [ElevatorServo] Loaded 2025-10-08T15:32:25.361Z,1759937545.361 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-10-08T15:32:25.383Z,1759937545.383 [MassServo] Loaded 2025-10-08T15:32:25.384Z,1759937545.384 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-10-08T15:32:25.405Z,1759937545.405 [RudderServo] Loaded 2025-10-08T15:32:25.406Z,1759937545.406 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-10-08T15:32:25.423Z,1759937545.423 [ThrusterHE] Loaded 2025-10-08T15:32:25.424Z,1759937545.424 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-10-08T15:32:25.424Z,1759937545.424 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-10-08T15:32:25.425Z,1759937545.425 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-10-08T15:32:25.572Z,1759937545.572 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-10-08T15:32:25.572Z,1759937545.572 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-10-08T15:32:25.587Z,1759937545.587 [NavChart] Loaded 2025-10-08T15:32:25.587Z,1759937545.587 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-10-08T15:32:25.608Z,1759937545.608 [UniversalFixResidualReporter] Loaded 2025-10-08T15:32:25.608Z,1759937545.608 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-10-08T15:32:25.609Z,1759937545.609 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-10-08T15:32:25.609Z,1759937545.609 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-10-08T15:32:25.702Z,1759937545.702 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-10-08T15:32:25.703Z,1759937545.703 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-10-08T15:32:27.070Z,1759937547.070 [AHRS_M2] Loaded 2025-10-08T15:32:27.071Z,1759937547.071 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-10-08T15:32:27.942Z,1759937547.942 [BPC1] Loaded 2025-10-08T15:32:27.943Z,1759937547.943 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-10-08T15:32:28.049Z,1759937548.049 [DAT] Loaded 2025-10-08T15:32:28.049Z,1759937548.049 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-10-08T15:32:28.050Z,1759937548.050 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4094D4E0 2025-10-08T15:32:28.051Z,1759937548.051 [DAT ThreadHandler](INFO): Protected caller Thread ID is 920 2025-10-08T15:32:28.195Z,1759937548.195 [DataOverHttps] Loaded 2025-10-08T15:32:28.195Z,1759937548.195 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-10-08T15:32:28.196Z,1759937548.196 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097D4E0 2025-10-08T15:32:28.197Z,1759937548.197 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 921 2025-10-08T15:32:28.222Z,1759937548.222 [Depth_Keller] Loaded 2025-10-08T15:32:28.222Z,1759937548.222 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-10-08T15:32:28.227Z,1759937548.227 [DropWeight] Loaded 2025-10-08T15:32:28.228Z,1759937548.228 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-10-08T15:32:28.295Z,1759937548.295 [NAL9602] Loaded 2025-10-08T15:32:28.295Z,1759937548.295 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-10-08T15:32:28.326Z,1759937548.326 [Onboard] Loaded 2025-10-08T15:32:28.327Z,1759937548.327 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-10-08T15:32:28.328Z,1759937548.328 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AD4E0 2025-10-08T15:32:28.328Z,1759937548.328 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922 2025-10-08T15:32:28.344Z,1759937548.344 [Power24vConverter] Loaded 2025-10-08T15:32:28.344Z,1759937548.344 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-10-08T15:32:28.361Z,1759937548.361 [Radio_Surface] Loaded 2025-10-08T15:32:28.361Z,1759937548.361 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-10-08T15:32:28.362Z,1759937548.362 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DD4E0 2025-10-08T15:32:28.362Z,1759937548.362 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923 2025-10-08T15:32:28.379Z,1759937548.379 [Sonardyne_Nano] Loaded 2025-10-08T15:32:28.379Z,1759937548.379 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-10-08T15:32:28.379Z,1759937548.379 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-10-08T15:32:28.380Z,1759937548.380 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-10-08T15:32:28.455Z,1759937548.455 [DepthRateCalculator] Loaded 2025-10-08T15:32:28.455Z,1759937548.455 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-10-08T15:32:28.461Z,1759937548.461 [PitchRateCalculator] Loaded 2025-10-08T15:32:28.461Z,1759937548.461 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-10-08T15:32:28.471Z,1759937548.471 [SpeedCalculator] Loaded 2025-10-08T15:32:28.471Z,1759937548.471 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-10-08T15:32:28.476Z,1759937548.476 [YawRateCalculator] Loaded 2025-10-08T15:32:28.476Z,1759937548.476 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-10-08T15:32:28.496Z,1759937548.496 [ElevatorOffsetCalculator] Loaded 2025-10-08T15:32:28.497Z,1759937548.497 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-10-08T15:32:28.497Z,1759937548.497 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-10-08T15:32:28.498Z,1759937548.498 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-10-08T15:32:28.689Z,1759937548.689 [CANONSampler] Loaded 2025-10-08T15:32:28.689Z,1759937548.689 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2025-10-08T15:32:28.754Z,1759937548.754 [CTD_Seabird] Loaded 2025-10-08T15:32:28.755Z,1759937548.755 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-10-08T15:32:28.756Z,1759937548.756 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A9B4E0 2025-10-08T15:32:28.756Z,1759937548.756 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 924 2025-10-08T15:32:28.780Z,1759937548.780 [PAR_Licor] Loaded 2025-10-08T15:32:28.780Z,1759937548.780 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-10-08T15:32:28.828Z,1759937548.828 [WetLabsBB2FL] Loaded 2025-10-08T15:32:28.829Z,1759937548.829 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-10-08T15:32:28.830Z,1759937548.830 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40ACB4E0 2025-10-08T15:32:28.830Z,1759937548.830 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 925 2025-10-08T15:32:28.831Z,1759937548.831 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-10-08T15:32:28.832Z,1759937548.832 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-10-08T15:32:28.881Z,1759937548.881 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-10-08T15:32:28.882Z,1759937548.882 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-10-08T15:32:29.324Z,1759937549.324 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-10-08T15:32:29.326Z,1759937549.326 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-10-08T15:32:29.537Z,1759937549.537 [SBIT](DEBUG): Construct Startup Built In Test. 2025-10-08T15:32:29.547Z,1759937549.547 [SBIT] Loaded 2025-10-08T15:32:29.548Z,1759937549.548 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-10-08T15:32:29.551Z,1759937549.551 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-10-08T15:32:29.565Z,1759937549.565 [IBIT] Loaded 2025-10-08T15:32:29.565Z,1759937549.565 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-10-08T15:32:29.571Z,1759937549.571 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-10-08T15:32:29.658Z,1759937549.658 [CBIT] Loaded 2025-10-08T15:32:29.658Z,1759937549.658 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-10-08T15:32:29.693Z,1759937549.693 [GFScanner] Loaded 2025-10-08T15:32:29.693Z,1759937549.693 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-10-08T15:32:29.694Z,1759937549.694 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-10-08T15:32:29.694Z,1759937549.694 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-10-08T15:32:29.874Z,1759937549.874 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-10-08T15:32:29.881Z,1759937549.881 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-10-08T15:32:29.884Z,1759937549.884 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-10-08T15:32:29.896Z,1759937549.896 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-10-08T15:32:29.897Z,1759937549.897 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C3D4E0 2025-10-08T15:32:29.897Z,1759937549.897 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 926 2025-10-08T15:32:29.902Z,1759937549.902 [Supervisor](INFO): Main Thread ID is 829 2025-10-08T15:32:29.902Z,1759937549.902 [Supervisor](DEBUG): Running supervisor. 2025-10-08T15:32:29.903Z,1759937549.903 [CommandExec ThreadHandler](INFO): Handler Thread ID is 927 2025-10-08T15:32:29.903Z,1759937549.903 [CommandExec](INFO): Initializing the command executive. 2025-10-08T15:32:29.905Z,1759937549.905 [CommandLine ThreadHandler](INFO): Handler Thread ID is 928 2025-10-08T15:32:29.907Z,1759937549.907 [controlThread ThreadHandler](INFO): Handler Thread ID is 929 2025-10-08T15:32:29.908Z,1759937549.908 [controlThread](DEBUG): Initializing ControlThread 2025-10-08T15:32:29.908Z,1759937549.908 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-10-08T15:32:29.910Z,1759937549.910 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-10-08T15:32:29.911Z,1759937549.911 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-10-08T15:32:29.911Z,1759937549.911 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-10-08T15:32:29.913Z,1759937549.913 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-10-08T15:32:29.914Z,1759937549.914 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-10-08T15:32:29.916Z,1759937549.916 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-10-08T15:32:29.917Z,1759937549.917 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-10-08T15:32:29.917Z,1759937549.917 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-10-08T15:32:29.918Z,1759937549.918 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-10-08T15:32:29.918Z,1759937549.918 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-10-08T15:32:29.920Z,1759937549.920 [SBIT](INFO): Initialize SBIT Component. 2025-10-08T15:32:29.921Z,1759937549.921 [SBIT](IMPORTANT): git: 2025-09-19 2025-10-08T15:32:29.921Z,1759937549.921 [SBIT](INFO): git hash: f5f7d10969816d125effdffd07357c8d50a3a0d0 2025-10-08T15:32:29.921Z,1759937549.921 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-10-08T15:32:29.922Z,1759937549.922 [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-10-08T15:32:29.923Z,1759937549.923 [SBIT](INFO): Beginning SBIT in 72.000000 seconds. 2025-10-08T15:32:29.924Z,1759937549.924 [IBIT](INFO): Initialize IBIT Component. 2025-10-08T15:32:29.925Z,1759937549.925 [CBIT](DEBUG): Initialize CBIT Component. 2025-10-08T15:32:29.926Z,1759937549.926 [logger ThreadHandler](INFO): Handler Thread ID is 930 2025-10-08T15:32:29.936Z,1759937549.936 [CBIT](DEBUG): Initialized mux pins. 2025-10-08T15:32:29.936Z,1759937549.936 [CBIT](DEBUG): Initializing the watchdog timer. 2025-10-08T15:32:29.944Z,1759937549.944 [DAT ThreadHandler](INFO): Handler Thread ID is 931 2025-10-08T15:32:29.945Z,1759937549.945 [DAT](INFO): Powering up 2025-10-08T15:32:29.945Z,1759937549.945 [DAT](DEBUG): Initializing DAT. 2025-10-08T15:32:29.949Z,1759937549.949 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 933 2025-10-08T15:32:29.951Z,1759937549.951 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-10-08T15:32:29.960Z,1759937549.960 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-10-08T15:32:29.960Z,1759937549.960 [CBIT](DEBUG): Initializing heartbeat. 2025-10-08T15:32:29.961Z,1759937549.961 [Onboard ThreadHandler](INFO): Handler Thread ID is 934 2025-10-08T15:32:29.981Z,1759937549.981 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 935 2025-10-08T15:32:29.996Z,1759937549.996 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 936 2025-10-08T15:32:29.997Z,1759937549.997 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-10-08T15:32:30.001Z,1759937550.001 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 938 2025-10-08T15:32:30.005Z,1759937550.005 [WetLabsBB2FL](INFO): Powering up 2025-10-08T15:32:30.006Z,1759937550.006 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 940 2025-10-08T15:32:30.016Z,1759937550.016 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-10-08T15:32:30.016Z,1759937550.016 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-10-08T15:32:30.016Z,1759937550.016 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-10-08T15:32:30.016Z,1759937550.016 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-10-08T15:32:30.017Z,1759937550.017 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-10-08T15:32:30.017Z,1759937550.017 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-10-08T15:32:30.017Z,1759937550.017 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-10-08T15:32:30.017Z,1759937550.017 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-10-08T15:32:30.032Z,1759937550.032 [CBIT](DEBUG): Deactivating emergency mode. 2025-10-08T15:32:30.072Z,1759937550.072 [CBIT](DEBUG): Backplane powered. 2025-10-08T15:32:30.072Z,1759937550.072 [GFScanner](DEBUG): Initializing GFScanner 2025-10-08T15:32:30.072Z,1759937550.072 [GFScanner](DEBUG): Deactivating GF circuits. 2025-10-08T15:32:30.077Z,1759937550.077 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-10-08T15:32:30.078Z,1759937550.078 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-10-08T15:32:30.078Z,1759937550.078 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-10-08T15:32:30.087Z,1759937550.087 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-10-08T15:32:30.154Z,1759937550.154 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-10-08T15:32:30.174Z,1759937550.174 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-10-08T15:32:30.208Z,1759937550.208 [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-10-08T15:32:30.209Z,1759937550.209 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-10-08T15:32:30.209Z,1759937550.209 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-10-08T15:32:30.220Z,1759937550.220 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-10-08T15:32:30.384Z,1759937550.384 [Radio_Surface](INFO): Powering up 2025-10-08T15:32:30.557Z,1759937550.557 [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-10-08T15:32:30.563Z,1759937550.563 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-10-08T15:32:30.584Z,1759937550.584 [Default:A.Wait](DEBUG): Construct Wait. 2025-10-08T15:32:30.586Z,1759937550.586 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-10-08T15:32:30.619Z,1759937550.619 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-10-08T15:32:30.622Z,1759937550.622 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-10-08T15:32:30.639Z,1759937550.639 [Default:E.Execute](DEBUG): Construct Execute. 2025-10-08T15:32:30.643Z,1759937550.643 [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-10-08T15:32:30.660Z,1759937550.660 [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-10-08T15:32:30.667Z,1759937550.667 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-10-08T15:32:30.800Z,1759937550.800 [Depth_Keller](INFO): Initializing. 2025-10-08T15:32:30.802Z,1759937550.802 [Power24vConverter](INFO): Powering up. 2025-10-08T15:32:30.802Z,1759937550.802 [Sonardyne_Nano](INFO): Initializing. 2025-10-08T15:32:30.820Z,1759937550.820 [CANONSampler](INFO): Powering down 2025-10-08T15:32:30.926Z,1759937550.926 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-10-08T15:32:30.949Z,1759937550.949 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-10-08T15:32:30.956Z,1759937550.956 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-10-08T15:32:30.957Z,1759937550.957 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-10-08T15:32:30.964Z,1759937550.964 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-10-08T15:32:30.965Z,1759937550.965 [MassServo](DEBUG): Initializing EZServoServo. 2025-10-08T15:32:30.972Z,1759937550.972 [MassServo](DEBUG): Initializing MassServo. 2025-10-08T15:32:30.973Z,1759937550.973 [RudderServo](DEBUG): Initializing EZServoServo. 2025-10-08T15:32:30.980Z,1759937550.980 [RudderServo](DEBUG): Initializing RudderServo. 2025-10-08T15:32:30.981Z,1759937550.981 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-10-08T15:32:30.988Z,1759937550.988 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-10-08T15:32:31.137Z,1759937551.137 [Depth_Keller](ERROR): Pressure or depth reading out of range: 915.616455 decibar, 0.000000 m 2025-10-08T15:32:31.192Z,1759937551.192 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-10-08T15:32:32.112Z,1759937552.112 [WetLabsBB2FL](INFO): Powering down 2025-10-08T15:32:33.094Z,1759937553.094 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-10-08T15:32:34.337Z,1759937554.337 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2025-10-08T15:32:34.743Z,1759937554.743 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-10-08T15:32:36.565Z,1759937556.565 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-10-08T15:32:41.789Z,1759937561.789 [DAT](INFO): DAT read: 2025-10-08T15:32:41.790Z,1759937561.790 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-10-08T15:32:43.301Z,1759937563.301 [DAT](INFO): DAT read: MF Frequency Band 2025-10-08T15:32:43.302Z,1759937563.302 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-10-08T15:32:43.303Z,1759937563.303 [DAT](INFO): DAT read: Oct 6 2025 23:16:22 2025-10-08T15:32:44.309Z,1759937564.309 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-10-08T15:32:44.310Z,1759937564.310 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-10-08T15:32:44.311Z,1759937564.311 [DAT](INFO): commRate: 1200 2025-10-08T15:32:46.376Z,1759937566.376 [DAT](INFO): entering command mode 2025-10-08T15:32:46.577Z,1759937566.577 [DAT](INFO): DAT read: 2025-10-08T15:32:46.577Z,1759937566.577 [DAT](INFO): DAT read: user:1> 2025-10-08T15:32:46.577Z,1759937566.577 [DAT](INFO): setting verbose to 3 2025-10-08T15:32:46.829Z,1759937566.829 [DAT](INFO): DAT read: user:1> 2025-10-08T15:32:46.830Z,1759937566.830 [DAT](INFO): DAT read: Verbose | 3 2025-10-08T15:32:46.830Z,1759937566.830 [DAT](INFO): set verbose to 3 2025-10-08T15:32:46.830Z,1759937566.830 [DAT](INFO): setting DatVerbose to 27440 2025-10-08T15:32:47.081Z,1759937567.081 [DAT](INFO): DAT read: user:2> 2025-10-08T15:32:47.082Z,1759937567.082 [DAT](INFO): DAT read: DatVerbose | 27440 2025-10-08T15:32:47.082Z,1759937567.082 [DAT](INFO): set DatVerbose to 27440 2025-10-08T15:32:47.082Z,1759937567.082 [DAT](INFO): setting transmit power to 8 2025-10-08T15:32:47.333Z,1759937567.333 [DAT](INFO): DAT read: user:3> 2025-10-08T15:32:47.334Z,1759937567.334 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-10-08T15:32:47.334Z,1759937567.334 [DAT](INFO): set transmit power to 8 2025-10-08T15:32:47.334Z,1759937567.334 [DAT](INFO): setting local address to 8 2025-10-08T15:32:47.584Z,1759937567.584 [DAT](INFO): DAT read: user:4> 2025-10-08T15:32:47.586Z,1759937567.586 [DAT](INFO): DAT read: LocalAddr | 8 2025-10-08T15:32:47.588Z,1759937567.588 [DAT](INFO): set local address to 8 2025-10-08T15:32:47.592Z,1759937567.592 [DAT](INFO): Setting time to: 15:32:47 And date to:10/8/2025 2025-10-08T15:32:47.837Z,1759937567.837 [DAT](INFO): DAT read: user:5> 2025-10-08T15:32:47.838Z,1759937567.838 [DAT](INFO): DAT read: Wed Oct 8, 2025 15:32:47 2025-10-08T15:32:47.838Z,1759937567.838 [DAT](INFO): Local DAT time set to Wed Oct 8, 2025 15:32:47 2025-10-08T15:32:58.558Z,1759937578.558 [NAL9602](INFO): Powering up NAL9602 2025-10-08T15:33:09.458Z,1759937589.458 [NAL9602](INFO): NAL9602 initialized 2025-10-08T15:33:36.124Z,1759937616.124 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T15:33:42.599Z,1759937622.599 [SBIT](IMPORTANT): Beginning Startup BIT 2025-10-08T15:33:42.604Z,1759937622.604 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-10-08T15:33:47.125Z,1759937627.125 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.007971 CHAN A1 (24V): 0.000516 CHAN A2 (12V): -0.001973 CHAN A3 (5V): -0.001151 CHAN B0 (3.3V): -0.000221 CHAN B1 (3.15aV): 0.000001 CHAN B2 (3.15bV): -0.000117 CHAN B3 (GND): 0.000346 OPEN: -0.000600 Full Scale: +/- 1 mA 2025-10-08T15:33:47.848Z,1759937627.848 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T15:34:36.391Z,1759937676.391 [SBIT](IMPORTANT): SBIT PASSED 2025-10-08T15:34:36.391Z,1759937676.391 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-10-08T15:34:36.392Z,1759937676.392 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=11 count; 2025-10-08T15:34:36.392Z,1759937676.392 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter; 2025-10-08T15:34:36.392Z,1759937676.392 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter; 2025-10-08T15:34:36.392Z,1759937676.392 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=259.524725 cubic_centimeter; 2025-10-08T15:34:36.392Z,1759937676.392 [SBIT](IMPORTANT): VerticalControl.massDefault=13.197035 millimeter; 2025-10-08T15:34:36.793Z,1759937676.793 [MissionManager](IMPORTANT): Started mission Startup 2025-10-08T15:34:36.793Z,1759937676.793 [Startup] Running Loop=1 2025-10-08T15:34:36.794Z,1759937676.794 [Startup](DEBUG): Aggregate::initialize Startup 2025-10-08T15:34:36.794Z,1759937676.794 [Startup:A.GoToSurface] Running Loop=1 2025-10-08T15:34:36.794Z,1759937676.794 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-10-08T15:34:36.794Z,1759937676.794 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-10-08T15:34:36.795Z,1759937676.795 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-10-08T15:34:36.795Z,1759937676.795 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-10-08T15:34:36.795Z,1759937676.795 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-10-08T15:34:36.796Z,1759937676.796 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-10-08T15:34:36.796Z,1759937676.796 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-10-08T15:34:36.798Z,1759937676.798 [Startup:StartupSatComms] Running Loop=1 2025-10-08T15:34:36.798Z,1759937676.798 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-10-08T15:34:36.798Z,1759937676.798 [Startup:StartupSatComms:A] Running Loop=1 2025-10-08T15:34:37.186Z,1759937677.186 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-10-08T15:35:00.022Z,1759937700.022 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004660 2025-10-08T15:35:30.005Z,1759937730.005 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-10-08T15:35:30.005Z,1759937730.005 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:35:30.021Z,1759937730.021 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:35:30.380Z,1759937730.380 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:35:30.380Z,1759937730.380 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-10-08T15:35:36.822Z,1759937736.822 [Startup:StartupSatComms:A](INFO): Timed out from 2025-10-08T15:34:36.8Z 2025-10-08T15:35:36.822Z,1759937736.822 [Startup:StartupSatComms:A] Stopped 2025-10-08T15:35:36.822Z,1759937736.822 [Startup:StartupSatComms:B] Running Loop=1 2025-10-08T15:35:37.233Z,1759937737.233 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-10-08T15:35:44.495Z,1759937744.495 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251008T153217/Courier0000.lzma 2025-10-08T15:35:45.497Z,1759937745.497 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0000.lzma.bak 2025-10-08T15:35:45.497Z,1759937745.497 [DataOverHttps](INFO): SBD MOMSN=26147514 2025-10-08T15:36:01.120Z,1759937761.120 [DataOverHttps](INFO): Sending 830 bytes from file Logs/20251008T153217/Express0001.lzma 2025-10-08T15:36:02.121Z,1759937762.121 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0001.lzma.bak 2025-10-08T15:36:02.121Z,1759937762.121 [DataOverHttps](INFO): SBD MOMSN=26147528 2025-10-08T15:36:03.493Z,1759937763.493 [Startup:StartupSatComms:B] Stopped 2025-10-08T15:36:03.493Z,1759937763.493 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-10-08T15:36:03.493Z,1759937763.493 [Startup:StartupSatComms] Stopped 2025-10-08T15:36:03.493Z,1759937763.493 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-10-08T15:36:03.494Z,1759937763.494 [Startup](INFO): Completed Startup 2025-10-08T15:36:03.494Z,1759937763.494 [MissionManager](INFO): Startup is completed. 2025-10-08T15:36:03.494Z,1759937763.494 [MissionManager](INFO): Uninitializing Mission Startup 2025-10-08T15:36:03.494Z,1759937763.494 [Startup] Stopped 2025-10-08T15:36:03.494Z,1759937763.494 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-10-08T15:36:03.494Z,1759937763.494 [Startup:A.GoToSurface] Stopped 2025-10-08T15:36:03.494Z,1759937763.494 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-10-08T15:36:03.893Z,1759937763.893 [MissionManager](IMPORTANT): Started mission Default 2025-10-08T15:36:03.893Z,1759937763.893 [Default] Running Loop=1 2025-10-08T15:36:03.893Z,1759937763.893 [Default](DEBUG): Aggregate::initialize Default 2025-10-08T15:36:03.893Z,1759937763.893 [Default:B.GoToSurface] Running Loop=1 2025-10-08T15:36:03.893Z,1759937763.893 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-10-08T15:36:03.894Z,1759937763.894 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-10-08T15:36:03.894Z,1759937763.894 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-10-08T15:36:03.894Z,1759937763.894 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-10-08T15:36:03.895Z,1759937763.895 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-10-08T15:36:03.919Z,1759937763.919 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-10-08T15:36:03.920Z,1759937763.920 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-10-08T15:36:03.920Z,1759937763.920 [Default:A.Wait] Running Loop=1 2025-10-08T15:36:03.920Z,1759937763.920 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-10-08T15:36:17.226Z,1759937777.226 [Default:A.Wait](INFO): Done Waiting. 2025-10-08T15:36:17.226Z,1759937777.226 [Default:A.Wait] Stopped 2025-10-08T15:36:17.226Z,1759937777.226 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T15:36:17.633Z,1759937777.633 [Default:CheckIn] Running Loop=1 2025-10-08T15:36:17.633Z,1759937777.633 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T15:36:17.633Z,1759937777.633 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T15:36:18.037Z,1759937778.037 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-10-08T15:36:22.460Z,1759937782.460 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:36:34.995Z,1759937794.995 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:36:47.635Z,1759937807.635 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:37:00.902Z,1759937820.902 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:37:14.240Z,1759937834.240 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:37:27.914Z,1759937847.914 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:37:40.835Z,1759937860.835 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:37:54.165Z,1759937874.165 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:38:06.691Z,1759937886.691 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:38:07.913Z,1759937887.913 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-10-08T15:38:11.945Z,1759937891.945 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-10-08T15:38:19.619Z,1759937899.619 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:38:30.964Z,1759937910.964 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-10-08T15:38:30.964Z,1759937910.964 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:38:30.975Z,1759937910.975 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:38:31.362Z,1759937911.362 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:38:31.362Z,1759937911.362 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-10-08T15:38:32.949Z,1759937912.949 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:38:45.879Z,1759937925.879 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T15:38:45.886Z,1759937925.886 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 5. 2025-10-08T15:38:45.889Z,1759937925.889 [BPC1](INFO): Received data from all battery sticks. 2025-10-08T15:41:17.797Z,1759938077.797 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-10-08T15:36:17.6Z 2025-10-08T15:41:17.797Z,1759938077.797 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T15:41:17.797Z,1759938077.797 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T15:41:18.218Z,1759938078.218 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-10-08T15:41:24.593Z,1759938084.593 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20251008T153217/Courier0004.lzma 2025-10-08T15:41:25.593Z,1759938085.593 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0004.lzma.bak 2025-10-08T15:41:25.593Z,1759938085.593 [DataOverHttps](INFO): SBD MOMSN=26147640 2025-10-08T15:41:31.952Z,1759938091.952 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-10-08T15:41:31.952Z,1759938091.952 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:41:31.963Z,1759938091.963 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:41:32.364Z,1759938092.364 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:41:32.364Z,1759938092.364 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-10-08T15:41:41.115Z,1759938101.115 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20251008T153217/Express0005.lzma 2025-10-08T15:41:42.117Z,1759938102.117 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0005.lzma.bak 2025-10-08T15:41:42.117Z,1759938102.117 [DataOverHttps](INFO): SBD MOMSN=26147642 2025-10-08T15:41:43.265Z,1759938103.265 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T15:41:43.265Z,1759938103.265 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T15:41:43.265Z,1759938103.265 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T15:43:12.121Z,1759938192.121 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-10-08T15:43:12.121Z,1759938192.121 [NAL9602] Data Fault, FailCount= 1 2025-10-08T15:43:12.121Z,1759938192.121 [NAL9602](ERROR): Data Fault 2025-10-08T15:43:12.138Z,1759938192.138 [CBIT](ERROR): Data Fault in component: NAL9602 2025-10-08T15:43:12.528Z,1759938192.528 [NAL9602](INFO): Powering down 2025-10-08T15:43:13.476Z,1759938193.476 [CBIT](INFO): Clearing failed state for component NAL9602 2025-10-08T15:43:13.476Z,1759938193.476 [NAL9602] No Fault, FailCount= 1 2025-10-08T15:43:42.824Z,1759938222.824 [NAL9602](INFO): Powering up NAL9602 2025-10-08T15:43:53.733Z,1759938233.733 [NAL9602](INFO): NAL9602 initialized 2025-10-08T15:44:32.928Z,1759938272.928 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-10-08T15:44:32.928Z,1759938272.928 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:44:32.959Z,1759938272.959 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:44:33.346Z,1759938273.346 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:44:33.346Z,1759938273.346 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-10-08T15:46:43.830Z,1759938403.830 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T15:46:43.831Z,1759938403.831 [Default:CheckIn:C.Wait] Stopped 2025-10-08T15:46:43.831Z,1759938403.831 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T15:46:43.831Z,1759938403.831 [Default:CheckIn:D] Running Loop=1 2025-10-08T15:46:44.228Z,1759938404.228 [Default:CheckIn:D] Stopped 2025-10-08T15:46:44.228Z,1759938404.228 [Default:CheckIn:E] Running Loop=1 2025-10-08T15:46:44.662Z,1759938404.662 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.672250 min 2025-10-08T15:46:44.662Z,1759938404.662 [Default:CheckIn:E] Stopped 2025-10-08T15:46:44.662Z,1759938404.662 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T15:46:44.662Z,1759938404.662 [Default:CheckIn] Stopped 2025-10-08T15:46:44.662Z,1759938404.662 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T15:46:44.663Z,1759938404.663 [Default:CheckIn](INFO): Running loop #2 2025-10-08T15:46:44.663Z,1759938404.663 [Default:CheckIn] Running Loop=2 2025-10-08T15:46:44.663Z,1759938404.663 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T15:46:44.663Z,1759938404.663 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T15:47:33.940Z,1759938453.940 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-10-08T15:47:33.940Z,1759938453.940 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:47:33.950Z,1759938453.950 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:47:34.343Z,1759938454.343 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:47:34.344Z,1759938454.344 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-10-08T15:49:03.244Z,1759938543.244 [CommandExec](IMPORTANT): got command burn on 2025-10-08T15:49:03.244Z,1759938543.244 [CommandExec](IMPORTANT): Activating dropweight wire 2025-10-08T15:50:14.528Z,1759938614.528 [CommandExec](IMPORTANT): got command burn off 2025-10-08T15:50:14.528Z,1759938614.528 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-10-08T15:50:34.946Z,1759938634.946 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-10-08T15:50:34.946Z,1759938634.946 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:50:34.956Z,1759938634.956 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:50:35.340Z,1759938635.340 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:50:35.341Z,1759938635.341 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-10-08T15:51:44.837Z,1759938704.837 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-10-08T15:46:44.7Z 2025-10-08T15:51:44.837Z,1759938704.837 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T15:51:44.837Z,1759938704.837 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T15:51:52.346Z,1759938712.346 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251008T153217/Courier0007.lzma 2025-10-08T15:51:53.361Z,1759938713.361 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0007.lzma.bak 2025-10-08T15:51:53.361Z,1759938713.361 [DataOverHttps](INFO): SBD MOMSN=26147772 2025-10-08T15:52:08.939Z,1759938728.939 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20251008T153217/Express0008.lzma 2025-10-08T15:52:09.941Z,1759938729.941 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0008.lzma.bak 2025-10-08T15:52:09.941Z,1759938729.941 [DataOverHttps](INFO): SBD MOMSN=26147774 2025-10-08T15:52:11.076Z,1759938731.076 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T15:52:11.076Z,1759938731.076 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T15:52:11.076Z,1759938731.076 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T15:53:35.955Z,1759938815.955 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2025-10-08T15:53:35.956Z,1759938815.956 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:53:35.966Z,1759938815.966 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:53:36.368Z,1759938816.368 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:53:36.369Z,1759938816.369 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2025-10-08T15:53:55.745Z,1759938835.745 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-10-08T15:53:55.745Z,1759938835.745 [NAL9602] Data Fault, FailCount= 2 2025-10-08T15:53:55.745Z,1759938835.745 [NAL9602](ERROR): Data Fault 2025-10-08T15:53:55.780Z,1759938835.780 [CBIT](ERROR): Data Fault in component: NAL9602 2025-10-08T15:53:56.149Z,1759938836.149 [NAL9602](INFO): Powering down 2025-10-08T15:53:56.977Z,1759938836.977 [CBIT](INFO): Clearing failed state for component NAL9602 2025-10-08T15:53:56.977Z,1759938836.977 [NAL9602] No Fault, FailCount= 2 2025-10-08T15:54:26.445Z,1759938866.445 [NAL9602](INFO): Powering up NAL9602 2025-10-08T15:54:37.357Z,1759938877.357 [NAL9602](INFO): NAL9602 initialized 2025-10-08T15:56:36.968Z,1759938996.968 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2025-10-08T15:56:36.968Z,1759938996.968 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:56:36.979Z,1759938996.979 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:56:37.374Z,1759938997.374 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:56:37.375Z,1759938997.375 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2025-10-08T15:57:11.694Z,1759939031.694 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T15:57:11.694Z,1759939031.694 [Default:CheckIn:C.Wait] Stopped 2025-10-08T15:57:11.694Z,1759939031.694 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T15:57:11.694Z,1759939031.694 [Default:CheckIn:D] Running Loop=1 2025-10-08T15:57:12.097Z,1759939032.097 [Default:CheckIn:D] Stopped 2025-10-08T15:57:12.097Z,1759939032.097 [Default:CheckIn:E] Running Loop=1 2025-10-08T15:57:12.521Z,1759939032.521 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.136721 min 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn:E] Stopped 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn] Stopped 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn](INFO): Running loop #3 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn] Running Loop=3 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T15:57:12.522Z,1759939032.522 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T15:59:37.980Z,1759939177.980 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2025-10-08T15:59:37.980Z,1759939177.980 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T15:59:37.990Z,1759939177.990 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T15:59:38.405Z,1759939178.405 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T15:59:38.405Z,1759939178.405 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2025-10-08T16:02:12.760Z,1759939332.760 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-10-08T15:57:12.5Z 2025-10-08T16:02:12.760Z,1759939332.760 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:02:12.761Z,1759939332.761 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:02:25.239Z,1759939345.239 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251008T153217/Courier0010.lzma 2025-10-08T16:02:26.241Z,1759939346.241 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0010.lzma.bak 2025-10-08T16:02:26.241Z,1759939346.241 [DataOverHttps](INFO): SBD MOMSN=26147898 2025-10-08T16:02:39.074Z,1759939359.074 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2025-10-08T16:02:39.074Z,1759939359.074 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T16:02:39.085Z,1759939359.085 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T16:02:39.524Z,1759939359.524 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T16:02:39.524Z,1759939359.524 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2025-10-08T16:02:45.851Z,1759939365.851 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251008T153217/Express0011.lzma 2025-10-08T16:02:46.853Z,1759939366.853 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0011.lzma.bak 2025-10-08T16:02:46.853Z,1759939366.853 [DataOverHttps](INFO): SBD MOMSN=26147900 2025-10-08T16:02:47.997Z,1759939367.997 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:02:47.997Z,1759939367.997 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:02:47.997Z,1759939367.997 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:04:39.509Z,1759939479.509 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-10-08T16:04:39.509Z,1759939479.509 [NAL9602] Data Fault, FailCount= 3 2025-10-08T16:04:39.510Z,1759939479.510 [NAL9602](ERROR): Data Fault 2025-10-08T16:04:39.527Z,1759939479.527 [CBIT](ERROR): Data Fault in component: NAL9602 2025-10-08T16:04:39.910Z,1759939479.910 [NAL9602](INFO): Powering down 2025-10-08T16:04:40.737Z,1759939480.737 [CBIT](INFO): Clearing failed state for component NAL9602 2025-10-08T16:04:40.737Z,1759939480.737 [NAL9602] No Fault, FailCount= 3 2025-10-08T16:05:10.212Z,1759939510.212 [NAL9602](INFO): Powering up NAL9602 2025-10-08T16:05:21.121Z,1759939521.121 [NAL9602](INFO): NAL9602 initialized 2025-10-08T16:05:40.116Z,1759939540.116 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2025-10-08T16:05:40.116Z,1759939540.116 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-10-08T16:05:40.144Z,1759939540.144 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-10-08T16:05:40.525Z,1759939540.525 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-10-08T16:05:40.525Z,1759939540.525 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2025-10-08T16:07:48.640Z,1759939668.640 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:07:48.640Z,1759939668.640 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:07:48.640Z,1759939668.640 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:07:48.640Z,1759939668.640 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:07:49.044Z,1759939669.044 [Default:CheckIn:D] Stopped 2025-10-08T16:07:49.044Z,1759939669.044 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:07:49.465Z,1759939669.465 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.752507 min 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn:E] Stopped 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn] Stopped 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn](INFO): Running loop #4 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn] Running Loop=4 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:07:49.466Z,1759939669.466 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:08:16.916Z,1759939696.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160815.00,A,3648.14377,N,12147.28467,W,0.797,0.00,081025,,,A*71 2025-10-08T16:08:16.919Z,1759939696.919 [NAL9602](INFO): GPS fix at 20251008T160815: (36.802396, -121.788078) 2025-10-08T16:08:16.936Z,1759939696.936 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:08:16.936Z,1759939696.936 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:08:31.747Z,1759939711.747 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20251008T153217/Courier0013.lzma 2025-10-08T16:08:32.749Z,1759939712.749 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0013.lzma.bak 2025-10-08T16:08:32.749Z,1759939712.749 [DataOverHttps](INFO): SBD MOMSN=26147974 2025-10-08T16:08:48.843Z,1759939728.843 [DataOverHttps](INFO): Sending 380 bytes from file Logs/20251008T153217/Express0014.lzma 2025-10-08T16:08:49.433Z,1759939729.433 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:08:49.845Z,1759939729.845 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0014.lzma.bak 2025-10-08T16:08:49.845Z,1759939729.845 [DataOverHttps](INFO): SBD MOMSN=26147977 2025-10-08T16:08:51.070Z,1759939731.070 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:08:51.070Z,1759939731.070 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:08:51.070Z,1759939731.070 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:13:51.636Z,1759940031.636 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:13:51.636Z,1759940031.636 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:13:51.636Z,1759940031.636 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:13:51.636Z,1759940031.636 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:13:52.056Z,1759940032.056 [Default:CheckIn:D] Stopped 2025-10-08T16:13:52.057Z,1759940032.057 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:13:52.448Z,1759940032.448 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.802718 min 2025-10-08T16:13:52.448Z,1759940032.448 [Default:CheckIn:E] Stopped 2025-10-08T16:13:52.448Z,1759940032.448 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:13:52.448Z,1759940032.448 [Default:CheckIn] Stopped 2025-10-08T16:13:52.448Z,1759940032.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:13:52.448Z,1759940032.448 [Default:CheckIn](INFO): Running loop #5 2025-10-08T16:13:52.448Z,1759940032.448 [Default:CheckIn] Running Loop=5 2025-10-08T16:13:52.449Z,1759940032.449 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:13:52.449Z,1759940032.449 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:13:54.460Z,1759940034.460 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161352.00,A,3648.14737,N,12147.22677,W,0.058,21.49,081025,,,A*4B 2025-10-08T16:13:54.462Z,1759940034.462 [NAL9602](INFO): GPS fix at 20251008T161352: (36.802456, -121.787113) 2025-10-08T16:13:54.473Z,1759940034.473 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:13:54.473Z,1759940034.473 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:14:02.159Z,1759940042.159 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153217/Courier0016.lzma 2025-10-08T16:14:03.161Z,1759940043.161 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0016.lzma.bak 2025-10-08T16:14:03.161Z,1759940043.161 [DataOverHttps](INFO): SBD MOMSN=26148022 2025-10-08T16:14:07.794Z,1759940047.794 [NAL9602](INFO): SBD MO Status=0, MOMSN=64860, MT Status=0, MTMSN=0 2025-10-08T16:14:07.794Z,1759940047.794 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:14:20.699Z,1759940060.699 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20251008T153217/Express0017.lzma 2025-10-08T16:14:21.701Z,1759940061.701 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0017.lzma.bak 2025-10-08T16:14:21.701Z,1759940061.701 [DataOverHttps](INFO): SBD MOMSN=26148026 2025-10-08T16:14:22.751Z,1759940062.751 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:14:22.751Z,1759940062.751 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:14:22.759Z,1759940062.759 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:14:38.524Z,1759940078.524 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:19:23.477Z,1759940363.477 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:19:23.477Z,1759940363.477 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:19:23.477Z,1759940363.477 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:19:23.477Z,1759940363.477 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:19:23.798Z,1759940363.798 [Default:CheckIn:D] Stopped 2025-10-08T16:19:23.799Z,1759940363.799 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:19:24.164Z,1759940364.164 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.331722 min 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn:E] Stopped 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn] Stopped 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn](INFO): Running loop #6 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn] Running Loop=6 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:19:24.165Z,1759940364.165 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:19:26.177Z,1759940366.177 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161925.00,A,3648.15452,N,12147.22436,W,0.428,16.06,081025,,,A*4B 2025-10-08T16:19:26.180Z,1759940366.180 [NAL9602](INFO): GPS fix at 20251008T161925: (36.802575, -121.787073) 2025-10-08T16:19:26.191Z,1759940366.191 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:19:26.191Z,1759940366.191 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:19:26.991Z,1759940366.991 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:19:26.991Z,1759940366.991 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:19:26.991Z,1759940366.991 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:19:52.435Z,1759940392.435 [NAL9602](INFO): SBD MO Status=2, MOMSN=64861, MT Status=2, MTMSN=0 2025-10-08T16:19:52.436Z,1759940392.436 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T16:20:19.906Z,1759940419.906 [NAL9602](INFO): SBD MO Status=2, MOMSN=64861, MT Status=2, MTMSN=0 2025-10-08T16:20:19.906Z,1759940419.906 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T16:20:38.491Z,1759940438.491 [NAL9602](INFO): SBD MO Status=2, MOMSN=64861, MT Status=2, MTMSN=0 2025-10-08T16:20:38.491Z,1759940438.491 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T16:20:47.391Z,1759940447.391 [NAL9602](INFO): SBD MO Status=0, MOMSN=64861, MT Status=0, MTMSN=0 2025-10-08T16:20:47.391Z,1759940447.391 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:21:18.081Z,1759940478.081 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:24:27.571Z,1759940667.571 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:24:27.571Z,1759940667.571 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:24:27.571Z,1759940667.571 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:24:27.571Z,1759940667.571 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:24:27.979Z,1759940667.979 [Default:CheckIn:D] Stopped 2025-10-08T16:24:27.979Z,1759940667.979 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:24:28.382Z,1759940668.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.401424 min 2025-10-08T16:24:28.382Z,1759940668.382 [Default:CheckIn:E] Stopped 2025-10-08T16:24:28.383Z,1759940668.383 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:24:28.383Z,1759940668.383 [Default:CheckIn] Stopped 2025-10-08T16:24:28.383Z,1759940668.383 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:24:28.383Z,1759940668.383 [Default:CheckIn](INFO): Running loop #7 2025-10-08T16:24:28.383Z,1759940668.383 [Default:CheckIn] Running Loop=7 2025-10-08T16:24:28.383Z,1759940668.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:24:28.383Z,1759940668.383 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:24:30.401Z,1759940670.401 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162429.00,A,3648.15216,N,12147.22078,W,0.058,16.06,081025,,,D*47 2025-10-08T16:24:30.403Z,1759940670.403 [NAL9602](INFO): GPS fix at 20251008T162429: (36.802536, -121.787013) 2025-10-08T16:24:30.414Z,1759940670.414 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:24:30.414Z,1759940670.414 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:24:38.214Z,1759940678.214 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0019.lzma 2025-10-08T16:24:39.217Z,1759940679.217 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0019.lzma.bak 2025-10-08T16:24:39.218Z,1759940679.218 [DataOverHttps](INFO): SBD MOMSN=26148137 2025-10-08T16:24:55.254Z,1759940695.254 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0022.lzma 2025-10-08T16:24:56.257Z,1759940696.257 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0022.lzma.bak 2025-10-08T16:24:56.257Z,1759940696.257 [DataOverHttps](INFO): SBD MOMSN=26148143 2025-10-08T16:25:12.127Z,1759940712.127 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251008T153217/Express0020.lzma 2025-10-08T16:25:13.130Z,1759940713.130 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0020.lzma.bak 2025-10-08T16:25:13.130Z,1759940713.130 [DataOverHttps](INFO): SBD MOMSN=26148149 2025-10-08T16:25:20.893Z,1759940720.893 [NAL9602](INFO): SBD MO Status=0, MOMSN=64862, MT Status=0, MTMSN=0 2025-10-08T16:25:20.894Z,1759940720.894 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:25:29.007Z,1759940729.007 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20251008T153217/Express0023.lzma 2025-10-08T16:25:30.009Z,1759940730.009 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0023.lzma.bak 2025-10-08T16:25:30.009Z,1759940730.009 [DataOverHttps](INFO): SBD MOMSN=26148152 2025-10-08T16:25:31.403Z,1759940731.403 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:25:31.404Z,1759940731.404 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:25:31.404Z,1759940731.404 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:25:51.596Z,1759940751.596 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:27:02.091Z,1759940822.091 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-10-08T16:28:42.232Z,1759940922.232 [DataOverHttps](IMPORTANT): SBD MTMSN=20251008T162841 2025-10-08T16:28:49.643Z,1759940929.643 [DataOverHttps](INFO): Received command: failc 2025-10-08T16:28:49.684Z,1759940929.684 [CommandExec](IMPORTANT): got command failComponent 2025-10-08T16:28:49.684Z,1759940929.684 [CommandExec](IMPORTANT): Failed components: 2025-10-08T16:28:49.684Z,1759940929.684 [CommandExec](IMPORTANT): No failed Components. 2025-10-08T16:28:50.644Z,1759940930.644 [DataOverHttps](IMPORTANT): SBD MTMSN=20251008T162849 2025-10-08T16:28:58.139Z,1759940938.139 [DataOverHttps](INFO): Received command: ibit 2025-10-08T16:28:58.212Z,1759940938.212 [CommandExec](IMPORTANT): got command ibit 2025-10-08T16:28:58.258Z,1759940938.258 [IBIT](IMPORTANT): Beginning Initiated BIT 2025-10-08T16:28:58.258Z,1759940938.258 [IBIT](IMPORTANT): Beginning control surface checks. 2025-10-08T16:28:58.282Z,1759940938.282 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-10-08T16:28:59.858Z,1759940939.858 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162859.00,A,3648.14186,N,12147.22413,W,0.175,16.06,081025,,,D*40 2025-10-08T16:28:59.861Z,1759940939.861 [NAL9602](INFO): GPS fix at 20251008T162859: (36.802364, -121.787069) 2025-10-08T16:29:02.795Z,1759940942.795 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.001284 CHAN A1 (24V): 0.000383 CHAN A2 (12V): -0.002480 CHAN A3 (5V): -0.001192 CHAN B0 (3.3V): 0.000178 CHAN B1 (3.15aV): -0.000472 CHAN B2 (3.15bV): -0.000687 CHAN B3 (GND): 0.000826 OPEN: -0.000626 Full Scale: +/- 1 mA 2025-10-08T16:29:16.850Z,1759940956.850 [NAL9602](INFO): SBD MO Status=0, MOMSN=64863, MT Status=0, MTMSN=0 2025-10-08T16:29:16.850Z,1759940956.850 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:29:18.064Z,1759940958.064 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162917.00,A,3648.14033,N,12147.22398,W,0.097,16.06,081025,,,D*4D 2025-10-08T16:29:18.066Z,1759940958.066 [NAL9602](INFO): GPS fix at 20251008T162917: (36.802339, -121.787066) 2025-10-08T16:29:20.890Z,1759940960.890 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162920.00,A,3648.14030,N,12147.22385,W,0.078,16.06,081025,,,D*47 2025-10-08T16:29:20.892Z,1759940960.892 [NAL9602](INFO): GPS fix at 20251008T162920: (36.802338, -121.787064) 2025-10-08T16:29:24.122Z,1759940964.122 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162923.00,A,3648.14011,N,12147.22370,W,0.058,16.06,081025,,,D*4F 2025-10-08T16:29:24.124Z,1759940964.124 [NAL9602](INFO): GPS fix at 20251008T162923: (36.802335, -121.787062) 2025-10-08T16:29:26.959Z,1759940966.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162926.00,A,3648.13998,N,12147.22353,W,0.039,16.06,081025,,,D*43 2025-10-08T16:29:26.962Z,1759940966.962 [NAL9602](INFO): GPS fix at 20251008T162926: (36.802333, -121.787059) 2025-10-08T16:29:29.782Z,1759940969.782 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162929.00,A,3648.13981,N,12147.22307,W,0.019,16.06,081025,,,D*47 2025-10-08T16:29:29.785Z,1759940969.785 [NAL9602](INFO): GPS fix at 20251008T162929: (36.802330, -121.787051) 2025-10-08T16:29:33.012Z,1759940973.012 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162932.00,A,3648.13976,N,12147.22310,W,0.039,16.06,081025,,,D*41 2025-10-08T16:29:33.014Z,1759940973.014 [NAL9602](INFO): GPS fix at 20251008T162932: (36.802329, -121.787052) 2025-10-08T16:29:35.842Z,1759940975.842 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162935.00,A,3648.13960,N,12147.22300,W,0.039,16.06,081025,,,D*40 2025-10-08T16:29:35.844Z,1759940975.844 [NAL9602](INFO): GPS fix at 20251008T162935: (36.802327, -121.787050) 2025-10-08T16:29:39.070Z,1759940979.070 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162938.00,A,3648.13921,N,12147.22297,W,0.039,16.06,081025,,,D*47 2025-10-08T16:29:39.072Z,1759940979.072 [NAL9602](INFO): GPS fix at 20251008T162938: (36.802320, -121.787049) 2025-10-08T16:29:41.902Z,1759940981.902 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162941.00,A,3648.13918,N,12147.22279,W,0.019,16.06,081025,,,D*41 2025-10-08T16:29:41.904Z,1759940981.904 [NAL9602](INFO): GPS fix at 20251008T162941: (36.802320, -121.787047) 2025-10-08T16:29:44.341Z,1759940984.341 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802319 Longitude: -121.787048 2025-10-08T16:29:44.755Z,1759940984.755 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.690001 2025-10-08T16:29:44.755Z,1759940984.755 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2025-10-08T16:29:44.756Z,1759940984.756 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2025-10-08T16:29:45.135Z,1759940985.135 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162944.00,A,3648.13937,N,12147.22271,W,0.039,16.06,081025,,,D*43 2025-10-08T16:29:45.137Z,1759940985.137 [NAL9602](INFO): GPS fix at 20251008T162944: (36.802323, -121.787045) 2025-10-08T16:29:45.173Z,1759940985.173 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2025-10-08T16:29:45.174Z,1759940985.174 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2025-10-08T16:29:45.174Z,1759940985.174 [IBIT](IMPORTANT): Pressure:9.490813 PSI 2025-10-08T16:29:45.174Z,1759940985.174 [IBIT](IMPORTANT): Humidity:17.598583 % 2025-10-08T16:29:45.593Z,1759940985.593 [IBIT](IMPORTANT): Vehicle Pitch:0.677858 degrees 2025-10-08T16:29:45.594Z,1759940985.594 [IBIT](IMPORTANT): Vehicle Roll:-1.616689 degrees 2025-10-08T16:29:45.594Z,1759940985.594 [IBIT](IMPORTANT): Vehicle Heading:208.312622 degrees 2025-10-08T16:29:45.955Z,1759940985.955 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2025-10-08T16:29:45.956Z,1759940985.956 [IBIT](IMPORTANT): buoyancyNeutral: 259.524719 cc 2025-10-08T16:29:45.956Z,1759940985.956 [IBIT](IMPORTANT): massDefault: 1.319703 cm 2025-10-08T16:29:45.956Z,1759940985.956 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2025-10-08T16:29:45.956Z,1759940985.956 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2025-10-08T16:29:45.956Z,1759940985.956 [IBIT](IMPORTANT): IBIT PASSED 2025-10-08T16:30:17.457Z,1759941017.457 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:30:32.011Z,1759941032.011 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:30:32.011Z,1759941032.011 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:30:32.011Z,1759941032.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:30:32.011Z,1759941032.011 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:30:32.415Z,1759941032.415 [Default:CheckIn:D] Stopped 2025-10-08T16:30:32.415Z,1759941032.415 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:30:32.821Z,1759941032.821 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.475362 min 2025-10-08T16:30:32.821Z,1759941032.821 [Default:CheckIn:E] Stopped 2025-10-08T16:30:32.821Z,1759941032.821 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:30:32.821Z,1759941032.821 [Default:CheckIn] Stopped 2025-10-08T16:30:32.822Z,1759941032.822 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:30:32.822Z,1759941032.822 [Default:CheckIn](INFO): Running loop #8 2025-10-08T16:30:32.822Z,1759941032.822 [Default:CheckIn] Running Loop=8 2025-10-08T16:30:32.822Z,1759941032.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:30:32.822Z,1759941032.822 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:30:34.830Z,1759941034.830 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163034.00,A,3648.14175,N,12147.22380,W,0.136,16.06,081025,,,D*44 2025-10-08T16:30:34.841Z,1759941034.841 [NAL9602](INFO): GPS fix at 20251008T163034: (36.802363, -121.787063) 2025-10-08T16:30:34.852Z,1759941034.852 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:30:34.852Z,1759941034.852 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:30:42.774Z,1759941042.774 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0025.lzma 2025-10-08T16:30:43.777Z,1759941043.777 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0025.lzma.bak 2025-10-08T16:30:43.777Z,1759941043.777 [DataOverHttps](INFO): SBD MOMSN=26148277 2025-10-08T16:30:56.650Z,1759941056.650 [NAL9602](INFO): SBD MO Status=0, MOMSN=64864, MT Status=0, MTMSN=0 2025-10-08T16:30:56.650Z,1759941056.650 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:30:59.865Z,1759941059.865 [DataOverHttps](INFO): Sending 1044 bytes from file Logs/20251008T153217/Express0026.lzma 2025-10-08T16:31:00.865Z,1759941060.865 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0026.lzma.bak 2025-10-08T16:31:00.865Z,1759941060.865 [DataOverHttps](INFO): SBD MOMSN=26148280 2025-10-08T16:31:16.858Z,1759941076.858 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20251008T153217/Express0029.lzma 2025-10-08T16:31:17.861Z,1759941077.861 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0029.lzma.bak 2025-10-08T16:31:17.861Z,1759941077.861 [DataOverHttps](INFO): SBD MOMSN=26148322 2025-10-08T16:31:18.898Z,1759941078.898 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:31:18.898Z,1759941078.898 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:31:18.898Z,1759941078.898 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:31:27.360Z,1759941087.360 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:36:19.521Z,1759941379.521 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:36:19.521Z,1759941379.521 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:36:19.521Z,1759941379.521 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:36:19.521Z,1759941379.521 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:36:19.926Z,1759941379.926 [Default:CheckIn:D] Stopped 2025-10-08T16:36:19.926Z,1759941379.926 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:36:20.334Z,1759941380.334 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.267220 min 2025-10-08T16:36:20.334Z,1759941380.334 [Default:CheckIn:E] Stopped 2025-10-08T16:36:20.334Z,1759941380.334 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:36:20.335Z,1759941380.335 [Default:CheckIn] Stopped 2025-10-08T16:36:20.335Z,1759941380.335 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:36:20.336Z,1759941380.336 [Default:CheckIn](INFO): Running loop #9 2025-10-08T16:36:20.336Z,1759941380.336 [Default:CheckIn] Running Loop=9 2025-10-08T16:36:20.336Z,1759941380.336 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:36:20.336Z,1759941380.336 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:36:22.344Z,1759941382.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163621.00,A,3648.16373,N,12147.20990,W,0.622,48.03,081025,,,D*45 2025-10-08T16:36:22.346Z,1759941382.346 [NAL9602](INFO): GPS fix at 20251008T163621: (36.802729, -121.786832) 2025-10-08T16:36:22.358Z,1759941382.358 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:36:22.358Z,1759941382.358 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:36:31.542Z,1759941391.542 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0031.lzma 2025-10-08T16:36:32.545Z,1759941392.545 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0031.lzma.bak 2025-10-08T16:36:32.545Z,1759941392.545 [DataOverHttps](INFO): SBD MOMSN=26148367 2025-10-08T16:36:48.631Z,1759941408.631 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20251008T153217/Express0032.lzma 2025-10-08T16:36:49.633Z,1759941409.633 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0032.lzma.bak 2025-10-08T16:36:49.633Z,1759941409.633 [DataOverHttps](INFO): SBD MOMSN=26148370 2025-10-08T16:36:50.676Z,1759941410.676 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:36:50.676Z,1759941410.676 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:36:50.676Z,1759941410.676 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:36:55.502Z,1759941415.502 [NAL9602](INFO): SBD MO Status=0, MOMSN=64865, MT Status=0, MTMSN=0 2025-10-08T16:36:55.502Z,1759941415.502 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:37:26.208Z,1759941446.208 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:39:52.047Z,1759941592.047 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:40:03.764Z,1759941603.764 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:40:15.481Z,1759941615.481 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:40:27.199Z,1759941627.199 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:40:38.915Z,1759941638.915 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:40:50.632Z,1759941650.632 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:41:02.350Z,1759941662.350 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:41:14.075Z,1759941674.075 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T16:41:51.244Z,1759941711.244 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:41:51.244Z,1759941711.244 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:41:51.244Z,1759941711.244 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:41:51.244Z,1759941711.244 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:41:51.655Z,1759941711.655 [Default:CheckIn:D] Stopped 2025-10-08T16:41:51.655Z,1759941711.655 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:41:52.054Z,1759941712.054 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.796021 min 2025-10-08T16:41:52.054Z,1759941712.054 [Default:CheckIn:E] Stopped 2025-10-08T16:41:52.054Z,1759941712.054 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:41:52.054Z,1759941712.054 [Default:CheckIn] Stopped 2025-10-08T16:41:52.054Z,1759941712.054 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:41:52.055Z,1759941712.055 [Default:CheckIn](INFO): Running loop #10 2025-10-08T16:41:52.055Z,1759941712.055 [Default:CheckIn] Running Loop=10 2025-10-08T16:41:52.055Z,1759941712.055 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:41:52.055Z,1759941712.055 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:41:54.083Z,1759941714.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164153.00,A,3648.16407,N,12147.21630,W,0.019,359.73,081025,,,A*7F 2025-10-08T16:41:54.086Z,1759941714.086 [NAL9602](INFO): GPS fix at 20251008T164153: (36.802734, -121.786938) 2025-10-08T16:41:54.097Z,1759941714.097 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:41:54.097Z,1759941714.097 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:42:01.451Z,1759941721.451 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0034.lzma 2025-10-08T16:42:02.453Z,1759941722.453 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0034.lzma.bak 2025-10-08T16:42:02.453Z,1759941722.453 [DataOverHttps](INFO): SBD MOMSN=26148443 2025-10-08T16:42:12.253Z,1759941732.253 [NAL9602](INFO): SBD MO Status=0, MOMSN=64866, MT Status=0, MTMSN=0 2025-10-08T16:42:12.254Z,1759941732.254 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:42:18.883Z,1759941738.883 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251008T153217/Express0035.lzma 2025-10-08T16:42:19.885Z,1759941739.885 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0035.lzma.bak 2025-10-08T16:42:19.885Z,1759941739.885 [DataOverHttps](INFO): SBD MOMSN=26148453 2025-10-08T16:42:21.158Z,1759941741.158 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:42:21.158Z,1759941741.158 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:42:21.158Z,1759941741.158 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:42:42.984Z,1759941762.984 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:43:48.828Z,1759941828.828 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:44:02.160Z,1759941842.160 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:44:15.492Z,1759941855.492 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:44:28.829Z,1759941868.829 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:44:41.351Z,1759941881.351 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:44:53.876Z,1759941893.876 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:45:06.401Z,1759941906.401 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:45:19.328Z,1759941919.328 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:45:32.254Z,1759941932.254 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:45:45.186Z,1759941945.186 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:45:58.514Z,1759941958.514 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T16:46:11.452Z,1759941971.452 [BPC1](INFO): Calculating totals. Valid battery stick count: 51. Valid reserve battery stick count: 5. 2025-10-08T16:46:11.455Z,1759941971.455 [BPC1](INFO): Received data from all battery sticks. 2025-10-08T16:47:21.754Z,1759942041.754 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:47:21.754Z,1759942041.754 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:47:21.754Z,1759942041.754 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:47:21.754Z,1759942041.754 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:47:22.166Z,1759942042.166 [Default:CheckIn:D] Stopped 2025-10-08T16:47:22.166Z,1759942042.166 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:47:22.562Z,1759942042.562 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.304549 min 2025-10-08T16:47:22.562Z,1759942042.562 [Default:CheckIn:E] Stopped 2025-10-08T16:47:22.563Z,1759942042.563 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:47:22.563Z,1759942042.563 [Default:CheckIn] Stopped 2025-10-08T16:47:22.563Z,1759942042.563 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:47:22.563Z,1759942042.563 [Default:CheckIn](INFO): Running loop #11 2025-10-08T16:47:22.563Z,1759942042.563 [Default:CheckIn] Running Loop=11 2025-10-08T16:47:22.563Z,1759942042.563 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:47:22.563Z,1759942042.563 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:47:24.570Z,1759942044.570 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164723.00,A,3648.16353,N,12147.21556,W,0.019,359.73,081025,,,A*7B 2025-10-08T16:47:24.573Z,1759942044.573 [NAL9602](INFO): GPS fix at 20251008T164723: (36.802726, -121.786926) 2025-10-08T16:47:24.584Z,1759942044.584 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:47:24.584Z,1759942044.584 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:47:32.394Z,1759942052.394 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20251008T153217/Courier0037.lzma 2025-10-08T16:47:33.397Z,1759942053.397 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0037.lzma.bak 2025-10-08T16:47:33.397Z,1759942053.397 [DataOverHttps](INFO): SBD MOMSN=26148493 2025-10-08T16:47:35.482Z,1759942055.482 [NAL9602](INFO): SBD MO Status=0, MOMSN=64867, MT Status=0, MTMSN=0 2025-10-08T16:47:35.482Z,1759942055.482 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:47:49.287Z,1759942069.287 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251008T153217/Express0038.lzma 2025-10-08T16:47:50.289Z,1759942070.289 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0038.lzma.bak 2025-10-08T16:47:50.289Z,1759942070.289 [DataOverHttps](INFO): SBD MOMSN=26148497 2025-10-08T16:47:51.657Z,1759942071.657 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:47:51.657Z,1759942071.657 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:47:51.657Z,1759942071.657 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:48:06.185Z,1759942086.185 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:52:52.266Z,1759942372.266 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:52:52.266Z,1759942372.266 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:52:52.266Z,1759942372.266 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:52:52.266Z,1759942372.266 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:52:52.675Z,1759942372.675 [Default:CheckIn:D] Stopped 2025-10-08T16:52:52.675Z,1759942372.675 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:52:53.074Z,1759942373.074 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.813029 min 2025-10-08T16:52:53.075Z,1759942373.075 [Default:CheckIn:E] Stopped 2025-10-08T16:52:53.075Z,1759942373.075 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:52:53.095Z,1759942373.095 [Default:CheckIn] Stopped 2025-10-08T16:52:53.095Z,1759942373.095 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:52:53.095Z,1759942373.095 [Default:CheckIn](INFO): Running loop #12 2025-10-08T16:52:53.095Z,1759942373.095 [Default:CheckIn] Running Loop=12 2025-10-08T16:52:53.095Z,1759942373.095 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:52:53.096Z,1759942373.096 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:52:55.079Z,1759942375.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165254.00,A,3648.16363,N,12147.21499,W,0.058,359.73,081025,,,A*7B 2025-10-08T16:52:55.082Z,1759942375.082 [NAL9602](INFO): GPS fix at 20251008T165254: (36.802727, -121.786917) 2025-10-08T16:52:55.092Z,1759942375.092 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:52:55.092Z,1759942375.092 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:53:02.690Z,1759942382.690 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0040.lzma 2025-10-08T16:53:03.693Z,1759942383.693 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0040.lzma.bak 2025-10-08T16:53:03.693Z,1759942383.693 [DataOverHttps](INFO): SBD MOMSN=26148622 2025-10-08T16:53:19.667Z,1759942399.667 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20251008T153217/Express0041.lzma 2025-10-08T16:53:20.669Z,1759942400.669 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0041.lzma.bak 2025-10-08T16:53:20.669Z,1759942400.669 [DataOverHttps](INFO): SBD MOMSN=26148625 2025-10-08T16:53:21.761Z,1759942401.761 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:53:21.761Z,1759942401.761 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:53:21.761Z,1759942401.761 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:53:35.883Z,1759942415.883 [NAL9602](INFO): SBD MO Status=0, MOMSN=64868, MT Status=0, MTMSN=0 2025-10-08T16:53:35.883Z,1759942415.883 [NAL9602](INFO): No messages in MT queue 2025-10-08T16:54:06.596Z,1759942446.596 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T16:58:22.359Z,1759942702.359 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T16:58:22.359Z,1759942702.359 [Default:CheckIn:C.Wait] Stopped 2025-10-08T16:58:22.359Z,1759942702.359 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T16:58:22.359Z,1759942702.359 [Default:CheckIn:D] Running Loop=1 2025-10-08T16:58:22.764Z,1759942702.764 [Default:CheckIn:D] Stopped 2025-10-08T16:58:22.764Z,1759942702.764 [Default:CheckIn:E] Running Loop=1 2025-10-08T16:58:23.175Z,1759942703.175 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.314518 min 2025-10-08T16:58:23.175Z,1759942703.175 [Default:CheckIn:E] Stopped 2025-10-08T16:58:23.183Z,1759942703.183 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T16:58:23.183Z,1759942703.183 [Default:CheckIn] Stopped 2025-10-08T16:58:23.183Z,1759942703.183 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T16:58:23.183Z,1759942703.183 [Default:CheckIn](INFO): Running loop #13 2025-10-08T16:58:23.184Z,1759942703.184 [Default:CheckIn] Running Loop=13 2025-10-08T16:58:23.184Z,1759942703.184 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T16:58:23.184Z,1759942703.184 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T16:58:25.166Z,1759942705.166 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165824.00,A,3648.16442,N,12147.21577,W,0.019,359.73,081025,,,A*76 2025-10-08T16:58:25.168Z,1759942705.168 [NAL9602](INFO): GPS fix at 20251008T165824: (36.802740, -121.786929) 2025-10-08T16:58:25.188Z,1759942705.188 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T16:58:25.188Z,1759942705.188 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T16:58:32.595Z,1759942712.595 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153217/Courier0043.lzma 2025-10-08T16:58:33.597Z,1759942713.597 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0043.lzma.bak 2025-10-08T16:58:33.597Z,1759942713.597 [DataOverHttps](INFO): SBD MOMSN=26148635 2025-10-08T16:58:46.786Z,1759942726.786 [NAL9602](INFO): SBD MO Status=2, MOMSN=64869, MT Status=2, MTMSN=0 2025-10-08T16:58:46.786Z,1759942726.786 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T16:58:49.615Z,1759942729.615 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251008T153217/Express0044.lzma 2025-10-08T16:58:50.617Z,1759942730.617 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0044.lzma.bak 2025-10-08T16:58:50.617Z,1759942730.617 [DataOverHttps](INFO): SBD MOMSN=26148638 2025-10-08T16:58:51.649Z,1759942731.649 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T16:58:51.649Z,1759942731.649 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T16:58:51.649Z,1759942731.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T16:59:21.129Z,1759942761.129 [NAL9602](INFO): SBD MO Status=2, MOMSN=64869, MT Status=2, MTMSN=0 2025-10-08T16:59:21.130Z,1759942761.130 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T16:59:38.497Z,1759942778.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=64869, MT Status=2, MTMSN=0 2025-10-08T16:59:38.498Z,1759942778.498 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T16:59:57.494Z,1759942797.494 [NAL9602](INFO): SBD MO Status=2, MOMSN=64869, MT Status=2, MTMSN=0 2025-10-08T16:59:57.494Z,1759942797.494 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T17:00:20.106Z,1759942820.106 [NAL9602](INFO): SBD MO Status=0, MOMSN=64869, MT Status=0, MTMSN=0 2025-10-08T17:00:20.106Z,1759942820.106 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:00:50.811Z,1759942850.811 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:03:52.223Z,1759943032.223 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:03:52.223Z,1759943032.223 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:03:52.223Z,1759943032.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:03:52.223Z,1759943032.223 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:03:52.627Z,1759943032.627 [Default:CheckIn:D] Stopped 2025-10-08T17:03:52.627Z,1759943032.627 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:03:53.033Z,1759943033.033 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.812223 min 2025-10-08T17:03:53.033Z,1759943033.033 [Default:CheckIn:E] Stopped 2025-10-08T17:03:53.034Z,1759943033.034 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:03:53.034Z,1759943033.034 [Default:CheckIn] Stopped 2025-10-08T17:03:53.034Z,1759943033.034 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:03:53.034Z,1759943033.034 [Default:CheckIn](INFO): Running loop #14 2025-10-08T17:03:53.034Z,1759943033.034 [Default:CheckIn] Running Loop=14 2025-10-08T17:03:53.034Z,1759943033.034 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:03:53.034Z,1759943033.034 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:03:55.043Z,1759943035.043 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170354.00,A,3648.16314,N,12147.21625,W,0.019,359.73,081025,,,A*7E 2025-10-08T17:03:55.045Z,1759943035.045 [NAL9602](INFO): GPS fix at 20251008T170354: (36.802719, -121.786937) 2025-10-08T17:03:55.077Z,1759943035.077 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:03:55.077Z,1759943035.077 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:04:02.258Z,1759943042.258 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0046.lzma 2025-10-08T17:04:03.261Z,1759943043.261 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0046.lzma.bak 2025-10-08T17:04:03.261Z,1759943043.261 [DataOverHttps](INFO): SBD MOMSN=26148749 2025-10-08T17:04:05.950Z,1759943045.950 [NAL9602](INFO): SBD MO Status=0, MOMSN=64870, MT Status=0, MTMSN=0 2025-10-08T17:04:05.950Z,1759943045.950 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:04:20.772Z,1759943060.772 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20251008T153217/Express0047.lzma 2025-10-08T17:04:21.773Z,1759943061.773 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0047.lzma.bak 2025-10-08T17:04:21.773Z,1759943061.773 [DataOverHttps](INFO): SBD MOMSN=26148752 2025-10-08T17:04:22.985Z,1759943062.985 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:04:22.985Z,1759943062.985 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:04:22.985Z,1759943062.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:04:36.694Z,1759943076.694 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:09:23.552Z,1759943363.552 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:09:23.552Z,1759943363.552 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:09:23.552Z,1759943363.552 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:09:23.552Z,1759943363.552 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:09:23.956Z,1759943363.956 [Default:CheckIn:D] Stopped 2025-10-08T17:09:23.956Z,1759943363.956 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:09:24.369Z,1759943364.369 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.334383 min 2025-10-08T17:09:24.369Z,1759943364.369 [Default:CheckIn:E] Stopped 2025-10-08T17:09:24.369Z,1759943364.369 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:09:24.369Z,1759943364.369 [Default:CheckIn] Stopped 2025-10-08T17:09:24.370Z,1759943364.370 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:09:24.370Z,1759943364.370 [Default:CheckIn](INFO): Running loop #15 2025-10-08T17:09:24.370Z,1759943364.370 [Default:CheckIn] Running Loop=15 2025-10-08T17:09:24.370Z,1759943364.370 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:09:24.370Z,1759943364.370 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:09:26.370Z,1759943366.370 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170925.00,A,3648.18970,N,12147.18687,W,3.654,41.71,081025,,,D*47 2025-10-08T17:09:26.372Z,1759943366.372 [NAL9602](INFO): GPS fix at 20251008T170925: (36.803162, -121.786448) 2025-10-08T17:09:26.383Z,1759943366.383 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:09:26.383Z,1759943366.383 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:09:27.189Z,1759943367.189 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:09:27.189Z,1759943367.189 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:09:27.189Z,1759943367.189 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:09:49.409Z,1759943389.409 [NAL9602](INFO): SBD MO Status=2, MOMSN=64871, MT Status=2, MTMSN=0 2025-10-08T17:09:49.410Z,1759943389.410 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T17:10:26.586Z,1759943426.586 [NAL9602](INFO): SBD MO Status=2, MOMSN=64871, MT Status=2, MTMSN=0 2025-10-08T17:10:26.586Z,1759943426.586 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T17:10:52.840Z,1759943452.840 [NAL9602](INFO): SBD MO Status=2, MOMSN=64871, MT Status=2, MTMSN=0 2025-10-08T17:10:52.840Z,1759943452.840 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T17:11:08.588Z,1759943468.588 [NAL9602](INFO): SBD MO Status=2, MOMSN=64871, MT Status=2, MTMSN=0 2025-10-08T17:11:08.588Z,1759943468.588 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T17:11:39.292Z,1759943499.292 [NAL9602](INFO): SBD MO Status=0, MOMSN=64871, MT Status=0, MTMSN=0 2025-10-08T17:11:39.292Z,1759943499.292 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:12:09.996Z,1759943529.996 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:14:27.769Z,1759943667.769 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:14:27.769Z,1759943667.769 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:14:27.769Z,1759943667.769 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:14:27.769Z,1759943667.769 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:14:28.175Z,1759943668.175 [Default:CheckIn:D] Stopped 2025-10-08T17:14:28.175Z,1759943668.175 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:14:28.579Z,1759943668.579 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.404687 min 2025-10-08T17:14:28.580Z,1759943668.580 [Default:CheckIn:E] Stopped 2025-10-08T17:14:28.580Z,1759943668.580 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:14:28.581Z,1759943668.581 [Default:CheckIn] Stopped 2025-10-08T17:14:28.581Z,1759943668.581 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:14:28.582Z,1759943668.582 [Default:CheckIn](INFO): Running loop #16 2025-10-08T17:14:28.583Z,1759943668.583 [Default:CheckIn] Running Loop=16 2025-10-08T17:14:28.584Z,1759943668.584 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:14:28.584Z,1759943668.584 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:14:30.590Z,1759943670.590 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171429.00,A,3648.48470,N,12147.11578,W,3.499,353.48,081025,,,D*7C 2025-10-08T17:14:30.593Z,1759943670.593 [NAL9602](INFO): GPS fix at 20251008T171429: (36.808078, -121.785263) 2025-10-08T17:14:30.624Z,1759943670.624 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:14:30.624Z,1759943670.624 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:14:38.322Z,1759943678.322 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153217/Courier0049.lzma 2025-10-08T17:14:39.325Z,1759943679.325 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0049.lzma.bak 2025-10-08T17:14:39.325Z,1759943679.325 [DataOverHttps](INFO): SBD MOMSN=26148877 2025-10-08T17:14:46.342Z,1759943686.342 [NAL9602](INFO): SBD MO Status=0, MOMSN=64872, MT Status=0, MTMSN=0 2025-10-08T17:14:46.342Z,1759943686.342 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:14:55.334Z,1759943695.334 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0052.lzma 2025-10-08T17:14:56.337Z,1759943696.337 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0052.lzma.bak 2025-10-08T17:14:56.337Z,1759943696.337 [DataOverHttps](INFO): SBD MOMSN=26148884 2025-10-08T17:15:12.263Z,1759943712.263 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20251008T153217/Express0050.lzma 2025-10-08T17:15:13.265Z,1759943713.265 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0050.lzma.bak 2025-10-08T17:15:13.265Z,1759943713.265 [DataOverHttps](INFO): SBD MOMSN=26148887 2025-10-08T17:15:17.052Z,1759943717.052 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:15:29.207Z,1759943729.207 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20251008T153217/Express0053.lzma 2025-10-08T17:15:30.209Z,1759943730.209 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0053.lzma.bak 2025-10-08T17:15:30.209Z,1759943730.209 [DataOverHttps](INFO): SBD MOMSN=26148890 2025-10-08T17:15:31.635Z,1759943731.635 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:15:31.635Z,1759943731.635 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:15:31.635Z,1759943731.635 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:20:32.191Z,1759944032.191 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:20:32.191Z,1759944032.191 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:20:32.191Z,1759944032.191 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:20:32.191Z,1759944032.191 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:20:32.586Z,1759944032.586 [Default:CheckIn:D] Stopped 2025-10-08T17:20:32.586Z,1759944032.586 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:20:32.990Z,1759944032.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.478215 min 2025-10-08T17:20:32.990Z,1759944032.990 [Default:CheckIn:E] Stopped 2025-10-08T17:20:32.991Z,1759944032.991 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:20:32.991Z,1759944032.991 [Default:CheckIn] Stopped 2025-10-08T17:20:32.991Z,1759944032.991 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:20:32.991Z,1759944032.991 [Default:CheckIn](INFO): Running loop #17 2025-10-08T17:20:32.991Z,1759944032.991 [Default:CheckIn] Running Loop=17 2025-10-08T17:20:32.991Z,1759944032.991 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:20:32.991Z,1759944032.991 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:20:34.999Z,1759944034.999 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172034.00,A,3648.32738,N,12147.55759,W,5.501,242.84,081025,,,D*73 2025-10-08T17:20:35.001Z,1759944035.001 [NAL9602](INFO): GPS fix at 20251008T172034: (36.805456, -121.792626) 2025-10-08T17:20:35.013Z,1759944035.013 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:20:35.013Z,1759944035.013 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:20:42.158Z,1759944042.158 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0055.lzma 2025-10-08T17:20:43.161Z,1759944043.161 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0055.lzma.bak 2025-10-08T17:20:43.161Z,1759944043.161 [DataOverHttps](INFO): SBD MOMSN=26148901 2025-10-08T17:20:50.754Z,1759944050.754 [NAL9602](INFO): SBD MO Status=0, MOMSN=64873, MT Status=0, MTMSN=0 2025-10-08T17:20:50.754Z,1759944050.754 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:20:59.155Z,1759944059.155 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251008T153217/Express0056.lzma 2025-10-08T17:21:00.157Z,1759944060.157 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0056.lzma.bak 2025-10-08T17:21:00.157Z,1759944060.157 [DataOverHttps](INFO): SBD MOMSN=26148904 2025-10-08T17:21:01.274Z,1759944061.274 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:21:01.274Z,1759944061.274 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:21:01.274Z,1759944061.274 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:21:21.457Z,1759944081.457 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:26:01.846Z,1759944361.846 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:26:01.846Z,1759944361.846 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:26:01.846Z,1759944361.846 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:26:01.846Z,1759944361.846 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:26:02.250Z,1759944362.250 [Default:CheckIn:D] Stopped 2025-10-08T17:26:02.250Z,1759944362.250 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:26:02.653Z,1759944362.653 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.972616 min 2025-10-08T17:26:02.653Z,1759944362.653 [Default:CheckIn:E] Stopped 2025-10-08T17:26:02.653Z,1759944362.653 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:26:02.653Z,1759944362.653 [Default:CheckIn] Stopped 2025-10-08T17:26:02.653Z,1759944362.653 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:26:02.654Z,1759944362.654 [Default:CheckIn](INFO): Running loop #18 2025-10-08T17:26:02.654Z,1759944362.654 [Default:CheckIn] Running Loop=18 2025-10-08T17:26:02.654Z,1759944362.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:26:02.654Z,1759944362.654 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:26:04.662Z,1759944364.662 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172603.00,A,3648.24104,N,12148.16244,W,5.909,268.62,081025,,,D*7A 2025-10-08T17:26:04.665Z,1759944364.665 [NAL9602](INFO): GPS fix at 20251008T172603: (36.804017, -121.802707) 2025-10-08T17:26:04.700Z,1759944364.700 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:26:04.700Z,1759944364.700 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:26:12.406Z,1759944372.406 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0058.lzma 2025-10-08T17:26:13.409Z,1759944373.409 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0058.lzma.bak 2025-10-08T17:26:13.409Z,1759944373.409 [DataOverHttps](INFO): SBD MOMSN=26149016 2025-10-08T17:26:17.198Z,1759944377.198 [NAL9602](INFO): SBD MO Status=0, MOMSN=64874, MT Status=0, MTMSN=0 2025-10-08T17:26:17.198Z,1759944377.198 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:26:33.095Z,1759944393.095 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20251008T153217/Express0059.lzma 2025-10-08T17:26:34.097Z,1759944394.097 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0059.lzma.bak 2025-10-08T17:26:34.097Z,1759944394.097 [DataOverHttps](INFO): SBD MOMSN=26149019 2025-10-08T17:26:35.439Z,1759944395.439 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:26:35.439Z,1759944395.439 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:26:35.439Z,1759944395.439 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:26:47.952Z,1759944407.952 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:30:08.579Z,1759944608.579 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-10-08T17:31:36.027Z,1759944696.027 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:31:36.027Z,1759944696.027 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:31:36.027Z,1759944696.027 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:31:36.027Z,1759944696.027 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:31:36.435Z,1759944696.435 [Default:CheckIn:D] Stopped 2025-10-08T17:31:36.435Z,1759944696.435 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:31:36.834Z,1759944696.834 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.542358 min 2025-10-08T17:31:36.834Z,1759944696.834 [Default:CheckIn:E] Stopped 2025-10-08T17:31:36.835Z,1759944696.835 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:31:36.835Z,1759944696.835 [Default:CheckIn] Stopped 2025-10-08T17:31:36.851Z,1759944696.851 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:31:36.851Z,1759944696.851 [Default:CheckIn](INFO): Running loop #19 2025-10-08T17:31:36.851Z,1759944696.851 [Default:CheckIn] Running Loop=19 2025-10-08T17:31:36.851Z,1759944696.851 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:31:36.851Z,1759944696.851 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:31:38.846Z,1759944698.846 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173138.00,A,3648.37496,N,12148.83131,W,6.084,278.77,081025,,,D*7F 2025-10-08T17:31:38.848Z,1759944698.848 [NAL9602](INFO): GPS fix at 20251008T173138: (36.806249, -121.813855) 2025-10-08T17:31:38.859Z,1759944698.859 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:31:38.859Z,1759944698.859 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:31:51.750Z,1759944711.750 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0061.lzma 2025-10-08T17:31:52.753Z,1759944712.753 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0061.lzma.bak 2025-10-08T17:31:52.753Z,1759944712.753 [DataOverHttps](INFO): SBD MOMSN=26149037 2025-10-08T17:31:53.794Z,1759944713.794 [NAL9602](INFO): SBD MO Status=0, MOMSN=64875, MT Status=0, MTMSN=0 2025-10-08T17:31:53.795Z,1759944713.795 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:32:08.755Z,1759944728.755 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20251008T153217/Express0062.lzma 2025-10-08T17:32:09.757Z,1759944729.757 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0062.lzma.bak 2025-10-08T17:32:09.757Z,1759944729.757 [DataOverHttps](INFO): SBD MOMSN=26149091 2025-10-08T17:32:10.780Z,1759944730.780 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:32:10.780Z,1759944730.780 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:32:10.780Z,1759944730.780 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:32:24.496Z,1759944744.496 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:33:41.465Z,1759944821.465 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-10-08T17:37:11.424Z,1759945031.424 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:37:11.424Z,1759945031.424 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:37:11.424Z,1759945031.424 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:37:11.424Z,1759945031.424 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:37:11.811Z,1759945031.811 [Default:CheckIn:D] Stopped 2025-10-08T17:37:11.811Z,1759945031.811 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:37:12.227Z,1759945032.227 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.131958 min 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn:E] Stopped 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn] Stopped 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn](INFO): Running loop #20 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn] Running Loop=20 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:37:12.228Z,1759945032.228 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:37:14.233Z,1759945034.233 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173713.00,A,3648.43360,N,12149.33872,W,0.778,80.45,081025,,,D*4F 2025-10-08T17:37:14.236Z,1759945034.236 [NAL9602](INFO): GPS fix at 20251008T173713: (36.807227, -121.822312) 2025-10-08T17:37:14.247Z,1759945034.247 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:37:14.247Z,1759945034.247 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:37:21.902Z,1759945041.902 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0064.lzma 2025-10-08T17:37:22.905Z,1759945042.905 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0064.lzma.bak 2025-10-08T17:37:22.905Z,1759945042.905 [DataOverHttps](INFO): SBD MOMSN=26149136 2025-10-08T17:37:28.770Z,1759945048.770 [NAL9602](INFO): SBD MO Status=0, MOMSN=64876, MT Status=0, MTMSN=0 2025-10-08T17:37:28.770Z,1759945048.770 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:37:42.975Z,1759945062.975 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20251008T153217/Express0065.lzma 2025-10-08T17:37:43.969Z,1759945063.969 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0065.lzma.bak 2025-10-08T17:37:43.969Z,1759945063.969 [DataOverHttps](INFO): SBD MOMSN=26149139 2025-10-08T17:37:45.342Z,1759945065.342 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:37:45.343Z,1759945065.343 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:37:45.343Z,1759945065.343 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:37:59.480Z,1759945079.480 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:42:46.016Z,1759945366.016 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:42:46.016Z,1759945366.016 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:42:46.016Z,1759945366.016 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:42:46.016Z,1759945366.016 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:42:46.419Z,1759945366.419 [Default:CheckIn:D] Stopped 2025-10-08T17:42:46.419Z,1759945366.419 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:42:46.824Z,1759945366.824 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.708757 min 2025-10-08T17:42:46.824Z,1759945366.824 [Default:CheckIn:E] Stopped 2025-10-08T17:42:46.824Z,1759945366.824 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:42:46.824Z,1759945366.824 [Default:CheckIn] Stopped 2025-10-08T17:42:46.824Z,1759945366.824 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:42:46.825Z,1759945366.825 [Default:CheckIn](INFO): Running loop #21 2025-10-08T17:42:46.825Z,1759945366.825 [Default:CheckIn] Running Loop=21 2025-10-08T17:42:46.825Z,1759945366.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:42:46.825Z,1759945366.825 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:42:48.830Z,1759945368.830 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174248.00,A,3648.44609,N,12149.33279,W,0.739,58.18,081025,,,D*47 2025-10-08T17:42:48.833Z,1759945368.833 [NAL9602](INFO): GPS fix at 20251008T174248: (36.807435, -121.822213) 2025-10-08T17:42:48.860Z,1759945368.860 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:42:48.860Z,1759945368.860 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:42:56.110Z,1759945376.110 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153217/Courier0067.lzma 2025-10-08T17:42:57.113Z,1759945377.113 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0067.lzma.bak 2025-10-08T17:42:57.113Z,1759945377.113 [DataOverHttps](INFO): SBD MOMSN=26149220 2025-10-08T17:43:04.613Z,1759945384.614 [NAL9602](INFO): SBD MO Status=0, MOMSN=64877, MT Status=0, MTMSN=0 2025-10-08T17:43:04.614Z,1759945384.614 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:43:13.107Z,1759945393.107 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20251008T153217/Express0068.lzma 2025-10-08T17:43:14.109Z,1759945394.109 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0068.lzma.bak 2025-10-08T17:43:14.109Z,1759945394.109 [DataOverHttps](INFO): SBD MOMSN=26149223 2025-10-08T17:43:15.142Z,1759945395.142 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:43:15.142Z,1759945395.142 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:43:15.142Z,1759945395.142 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:43:35.318Z,1759945415.318 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:45:46.907Z,1759945546.907 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-10-08T17:46:18.035Z,1759945578.035 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-10-08T17:47:18.012Z,1759945638.012 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T17:47:30.132Z,1759945650.132 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T17:47:41.848Z,1759945661.848 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T17:47:53.967Z,1759945673.967 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T17:48:06.087Z,1759945686.087 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T17:48:15.803Z,1759945695.803 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:48:15.803Z,1759945695.803 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:48:15.803Z,1759945695.803 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:48:15.803Z,1759945695.803 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:48:16.203Z,1759945696.203 [Default:CheckIn:D] Stopped 2025-10-08T17:48:16.203Z,1759945696.203 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:48:16.611Z,1759945696.611 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.205151 min 2025-10-08T17:48:16.611Z,1759945696.611 [Default:CheckIn:E] Stopped 2025-10-08T17:48:16.612Z,1759945696.612 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:48:16.612Z,1759945696.612 [Default:CheckIn] Stopped 2025-10-08T17:48:16.612Z,1759945696.612 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:48:16.612Z,1759945696.612 [Default:CheckIn](INFO): Running loop #22 2025-10-08T17:48:16.612Z,1759945696.612 [Default:CheckIn] Running Loop=22 2025-10-08T17:48:16.612Z,1759945696.612 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:48:16.612Z,1759945696.612 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:48:18.215Z,1759945698.215 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T17:48:18.638Z,1759945698.638 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174817.00,A,3648.18427,N,12149.88834,W,21.266,260.43,081025,,,D*48 2025-10-08T17:48:18.640Z,1759945698.640 [NAL9602](INFO): GPS fix at 20251008T174817: (36.803071, -121.831472) 2025-10-08T17:48:18.660Z,1759945698.660 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:48:18.660Z,1759945698.660 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:48:29.351Z,1759945709.351 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0070.lzma 2025-10-08T17:48:30.353Z,1759945710.353 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0070.lzma.bak 2025-10-08T17:48:30.353Z,1759945710.353 [DataOverHttps](INFO): SBD MOMSN=26149273 2025-10-08T17:48:30.416Z,1759945710.416 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-10-08T17:48:37.676Z,1759945717.676 [NAL9602](INFO): SBD MO Status=0, MOMSN=64878, MT Status=0, MTMSN=0 2025-10-08T17:48:37.676Z,1759945717.676 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:48:43.323Z,1759945723.323 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:48:46.275Z,1759945726.275 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20251008T153217/Express0071.lzma 2025-10-08T17:48:47.277Z,1759945727.277 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0071.lzma.bak 2025-10-08T17:48:47.277Z,1759945727.277 [DataOverHttps](INFO): SBD MOMSN=26149277 2025-10-08T17:48:48.591Z,1759945728.591 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:48:48.595Z,1759945728.595 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:48:48.595Z,1759945728.595 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:49:08.368Z,1759945748.368 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:51:10.439Z,1759945870.439 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:51:23.367Z,1759945883.367 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:51:36.700Z,1759945896.700 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:51:49.628Z,1759945909.628 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:52:02.958Z,1759945922.958 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:52:15.886Z,1759945935.886 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:52:28.857Z,1759945948.857 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:52:42.199Z,1759945962.199 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:52:55.139Z,1759945975.139 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:53:08.067Z,1759945988.067 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:53:20.990Z,1759946000.990 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:53:34.327Z,1759946014.327 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-10-08T17:53:34.334Z,1759946014.334 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 5. 2025-10-08T17:53:34.337Z,1759946014.337 [BPC1](INFO): Received data from all battery sticks. 2025-10-08T17:53:49.283Z,1759946029.283 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:53:49.283Z,1759946029.283 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:53:49.283Z,1759946029.283 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:53:49.283Z,1759946029.283 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:53:49.691Z,1759946029.691 [Default:CheckIn:D] Stopped 2025-10-08T17:53:49.691Z,1759946029.691 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:53:50.089Z,1759946030.089 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.763298 min 2025-10-08T17:53:50.089Z,1759946030.089 [Default:CheckIn:E] Stopped 2025-10-08T17:53:50.089Z,1759946030.089 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:53:50.089Z,1759946030.089 [Default:CheckIn] Stopped 2025-10-08T17:53:50.090Z,1759946030.090 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:53:50.090Z,1759946030.090 [Default:CheckIn](INFO): Running loop #23 2025-10-08T17:53:50.090Z,1759946030.090 [Default:CheckIn] Running Loop=23 2025-10-08T17:53:50.090Z,1759946030.090 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:53:50.090Z,1759946030.090 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:53:52.098Z,1759946032.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175351.00,A,3647.80346,N,12150.83219,W,0.622,227.93,081025,,,D*71 2025-10-08T17:53:52.109Z,1759946032.109 [NAL9602](INFO): GPS fix at 20251008T175351: (36.796724, -121.847203) 2025-10-08T17:53:52.120Z,1759946032.120 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:53:52.120Z,1759946032.120 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:53:59.511Z,1759946039.511 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20251008T153217/Courier0073.lzma 2025-10-08T17:54:00.513Z,1759946040.513 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0073.lzma.bak 2025-10-08T17:54:00.513Z,1759946040.513 [DataOverHttps](INFO): SBD MOMSN=26149352 2025-10-08T17:54:13.910Z,1759946053.910 [NAL9602](INFO): SBD MO Status=2, MOMSN=64879, MT Status=2, MTMSN=0 2025-10-08T17:54:13.910Z,1759946053.910 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T17:54:17.491Z,1759946057.491 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20251008T153217/Express0074.lzma 2025-10-08T17:54:18.493Z,1759946058.493 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Express0074.lzma.bak 2025-10-08T17:54:18.493Z,1759946058.493 [DataOverHttps](INFO): SBD MOMSN=26149356 2025-10-08T17:54:19.594Z,1759946059.594 [Default:CheckIn:Read_Iridium] Stopped 2025-10-08T17:54:19.594Z,1759946059.594 [Default:CheckIn:C.Wait] Running Loop=1 2025-10-08T17:54:19.594Z,1759946059.594 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-10-08T17:54:38.618Z,1759946078.618 [NAL9602](INFO): SBD MO Status=2, MOMSN=64879, MT Status=2, MTMSN=0 2025-10-08T17:54:38.618Z,1759946078.618 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-10-08T17:55:01.264Z,1759946101.264 [NAL9602](INFO): SBD MO Status=0, MOMSN=64879, MT Status=0, MTMSN=0 2025-10-08T17:55:01.264Z,1759946101.264 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:55:31.968Z,1759946131.968 [NAL9602](INFO): Not Powering down - fast GPS 2025-10-08T17:59:20.272Z,1759946360.272 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-10-08T17:59:20.272Z,1759946360.272 [Default:CheckIn:C.Wait] Stopped 2025-10-08T17:59:20.272Z,1759946360.272 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-10-08T17:59:20.272Z,1759946360.272 [Default:CheckIn:D] Running Loop=1 2025-10-08T17:59:20.686Z,1759946360.686 [Default:CheckIn:D] Stopped 2025-10-08T17:59:20.686Z,1759946360.686 [Default:CheckIn:E] Running Loop=1 2025-10-08T17:59:21.074Z,1759946361.074 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.279883 min 2025-10-08T17:59:21.074Z,1759946361.074 [Default:CheckIn:E] Stopped 2025-10-08T17:59:21.075Z,1759946361.075 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-10-08T17:59:21.075Z,1759946361.075 [Default:CheckIn] Stopped 2025-10-08T17:59:21.075Z,1759946361.075 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-10-08T17:59:21.075Z,1759946361.075 [Default:CheckIn](INFO): Running loop #24 2025-10-08T17:59:21.075Z,1759946361.075 [Default:CheckIn] Running Loop=24 2025-10-08T17:59:21.075Z,1759946361.075 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-10-08T17:59:21.075Z,1759946361.075 [Default:CheckIn:Read_GPS] Running Loop=1 2025-10-08T17:59:23.083Z,1759946363.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175922.00,A,3647.81114,N,12150.95568,W,0.350,8.80,081025,,,D*70 2025-10-08T17:59:23.085Z,1759946363.085 [NAL9602](INFO): GPS fix at 20251008T175922: (36.796852, -121.849261) 2025-10-08T17:59:23.096Z,1759946363.096 [Default:CheckIn:Read_GPS] Stopped 2025-10-08T17:59:23.096Z,1759946363.096 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-10-08T17:59:30.654Z,1759946370.654 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153217/Courier0076.lzma 2025-10-08T17:59:31.657Z,1759946371.657 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153217/Courier0076.lzma.bak 2025-10-08T17:59:31.657Z,1759946371.657 [DataOverHttps](IMPORTANT): SBD MOMSN=26149423, MTMSN=20251008T175930 2025-10-08T17:59:33.191Z,1759946373.191 [NAL9602](INFO): SBD MO Status=0, MOMSN=64880, MT Status=0, MTMSN=0 2025-10-08T17:59:33.192Z,1759946373.192 [NAL9602](INFO): No messages in MT queue 2025-10-08T17:59:39.015Z,1759946379.015 [DataOverHttps](INFO): Received command: restart logs