2025-05-19T14:33:46.191Z,1747665226.191 [Supervisor](DEBUG): Initializing supervisor. 2025-05-19T14:33:46.196Z,1747665226.196 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-05-19T14:33:46.196Z,1747665226.196 [SyncHandler](INFO): Protected caller Thread ID is 840 2025-05-19T14:33:46.197Z,1747665226.197 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-05-19T14:33:46.198Z,1747665226.198 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-05-19T14:33:46.198Z,1747665226.198 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 841 2025-05-19T14:33:46.202Z,1747665226.202 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-05-19T14:33:46.222Z,1747665226.222 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-05-19T14:33:46.223Z,1747665226.223 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-05-19T14:33:46.224Z,1747665226.224 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 842 2025-05-19T14:33:46.228Z,1747665226.228 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-05-19T14:33:46.229Z,1747665226.229 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-05-19T14:33:46.229Z,1747665226.229 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 843 2025-05-19T14:33:46.232Z,1747665226.232 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-05-19T14:33:46.233Z,1747665226.233 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-05-19T14:33:46.233Z,1747665226.233 [logger ThreadHandler](INFO): Protected caller Thread ID is 844 2025-05-19T14:33:46.237Z,1747665226.237 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-05-19T14:33:46.237Z,1747665226.237 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-05-19T14:33:46.241Z,1747665226.241 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-05-19T14:33:46.569Z,1747665226.569 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-05-19T14:33:46.571Z,1747665226.571 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-05-19T14:33:46.662Z,1747665226.662 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-05-19T14:33:47.196Z,1747665227.196 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-05-19T14:33:47.198Z,1747665227.198 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-05-19T14:33:47.551Z,1747665227.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-05-19T14:33:47.553Z,1747665227.553 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-05-19T14:33:47.659Z,1747665227.659 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-05-19T14:33:47.661Z,1747665227.661 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-05-19T14:33:48.091Z,1747665228.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-05-19T14:33:48.093Z,1747665228.093 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-05-19T14:33:48.335Z,1747665228.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-05-19T14:33:48.335Z,1747665228.335 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-05-19T14:33:48.883Z,1747665228.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-05-19T14:33:48.885Z,1747665228.885 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-05-19T14:33:49.036Z,1747665229.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-05-19T14:33:49.038Z,1747665229.038 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-05-19T14:33:49.425Z,1747665229.425 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-05-19T14:33:50.544Z,1747665230.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-05-19T14:33:50.545Z,1747665230.545 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-05-19T14:33:51.034Z,1747665231.034 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-05-19T14:33:51.035Z,1747665231.035 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-05-19T14:33:51.231Z,1747665231.231 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-05-19T14:33:51.233Z,1747665231.233 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-05-19T14:33:51.355Z,1747665231.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-05-19T14:33:51.356Z,1747665231.356 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-05-19T14:33:51.595Z,1747665231.595 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-05-19T14:33:51.597Z,1747665231.597 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-05-19T14:33:51.857Z,1747665231.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-05-19T14:33:51.859Z,1747665231.859 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2025-05-19T14:33:51.862Z,1747665231.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2025-05-19T14:33:51.959Z,1747665231.959 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2025-05-19T14:33:52.073Z,1747665232.073 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2025-05-19T14:33:52.168Z,1747665232.168 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2025-05-19T14:33:52.281Z,1747665232.281 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2025-05-19T14:33:52.386Z,1747665232.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2025-05-19T14:33:52.515Z,1747665232.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2025-05-19T14:33:52.678Z,1747665232.678 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2025-05-19T14:33:52.836Z,1747665232.836 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2025-05-19T14:33:52.957Z,1747665232.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2025-05-19T14:33:53.233Z,1747665233.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-05-19T14:33:53.234Z,1747665233.234 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2025-05-19T14:33:53.235Z,1747665233.235 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-05-19T14:33:53.247Z,1747665233.247 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-05-19T14:33:53.319Z,1747665233.319 [VerticalControl](DEBUG): Construct VerticalControl. 2025-05-19T14:33:53.383Z,1747665233.383 [VerticalControl] Loaded 2025-05-19T14:33:53.383Z,1747665233.383 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-05-19T14:33:53.386Z,1747665233.386 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-05-19T14:33:53.434Z,1747665233.434 [HorizontalControl] Loaded 2025-05-19T14:33:53.434Z,1747665233.434 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-05-19T14:33:53.436Z,1747665233.436 [SpeedControl](DEBUG): Construct SpeedControl. 2025-05-19T14:33:53.440Z,1747665233.440 [SpeedControl] Loaded 2025-05-19T14:33:53.440Z,1747665233.440 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-05-19T14:33:53.443Z,1747665233.443 [LoopControl](DEBUG): Construct LoopControl. 2025-05-19T14:33:53.443Z,1747665233.443 [LoopControl] Loaded 2025-05-19T14:33:53.443Z,1747665233.443 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-05-19T14:33:53.444Z,1747665233.444 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-05-19T14:33:53.446Z,1747665233.446 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-05-19T14:33:53.462Z,1747665233.462 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-05-19T14:33:53.462Z,1747665233.462 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-05-19T14:33:53.681Z,1747665233.681 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-05-19T14:33:53.682Z,1747665233.682 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-05-19T14:33:53.873Z,1747665233.873 [BuoyancyServo] Loaded 2025-05-19T14:33:53.873Z,1747665233.873 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-05-19T14:33:53.896Z,1747665233.896 [ElevatorServo] Loaded 2025-05-19T14:33:53.896Z,1747665233.896 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-05-19T14:33:53.918Z,1747665233.918 [MassServo] Loaded 2025-05-19T14:33:53.918Z,1747665233.918 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-05-19T14:33:53.938Z,1747665233.938 [RudderServo] Loaded 2025-05-19T14:33:53.939Z,1747665233.939 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-05-19T14:33:53.956Z,1747665233.956 [ThrusterHE] Loaded 2025-05-19T14:33:53.956Z,1747665233.956 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-05-19T14:33:53.956Z,1747665233.956 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-05-19T14:33:53.957Z,1747665233.957 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-05-19T14:33:54.097Z,1747665234.097 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-05-19T14:33:54.098Z,1747665234.098 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-05-19T14:33:54.112Z,1747665234.112 [NavChart] Loaded 2025-05-19T14:33:54.112Z,1747665234.112 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-05-19T14:33:54.161Z,1747665234.161 [UniversalFixResidualReporter] Loaded 2025-05-19T14:33:54.162Z,1747665234.162 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-05-19T14:33:54.162Z,1747665234.162 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-05-19T14:33:54.163Z,1747665234.163 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-05-19T14:33:55.151Z,1747665235.151 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-05-19T14:33:55.152Z,1747665235.152 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-05-19T14:33:56.151Z,1747665236.151 [AHRS_M2] Loaded 2025-05-19T14:33:56.151Z,1747665236.151 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-05-19T14:33:56.965Z,1747665236.965 [BPC1] Loaded 2025-05-19T14:33:56.965Z,1747665236.965 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-05-19T14:33:57.065Z,1747665237.065 [DAT] Loaded 2025-05-19T14:33:57.065Z,1747665237.065 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-05-19T14:33:57.066Z,1747665237.066 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4094B4E0 2025-05-19T14:33:57.067Z,1747665237.067 [DAT ThreadHandler](INFO): Protected caller Thread ID is 924 2025-05-19T14:33:57.397Z,1747665237.397 [DataOverHttps] Loaded 2025-05-19T14:33:57.397Z,1747665237.397 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-05-19T14:33:57.398Z,1747665237.398 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097B4E0 2025-05-19T14:33:57.398Z,1747665237.398 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925 2025-05-19T14:33:57.421Z,1747665237.421 [Depth_Keller] Loaded 2025-05-19T14:33:57.422Z,1747665237.422 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-05-19T14:33:57.427Z,1747665237.427 [DropWeight] Loaded 2025-05-19T14:33:57.427Z,1747665237.427 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-05-19T14:33:57.491Z,1747665237.491 [NAL9602] Loaded 2025-05-19T14:33:57.491Z,1747665237.491 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-05-19T14:33:57.521Z,1747665237.521 [Onboard] Loaded 2025-05-19T14:33:57.522Z,1747665237.522 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-05-19T14:33:57.523Z,1747665237.523 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AB4E0 2025-05-19T14:33:57.523Z,1747665237.523 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926 2025-05-19T14:33:57.537Z,1747665237.537 [Power24vConverter] Loaded 2025-05-19T14:33:57.538Z,1747665237.538 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-05-19T14:33:57.554Z,1747665237.554 [Radio_Surface] Loaded 2025-05-19T14:33:57.554Z,1747665237.554 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-05-19T14:33:57.555Z,1747665237.555 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0 2025-05-19T14:33:57.556Z,1747665237.556 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927 2025-05-19T14:33:57.571Z,1747665237.571 [Sonardyne_Nano] Loaded 2025-05-19T14:33:57.571Z,1747665237.571 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-05-19T14:33:57.572Z,1747665237.572 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-05-19T14:33:57.573Z,1747665237.573 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-05-19T14:33:57.644Z,1747665237.644 [DepthRateCalculator] Loaded 2025-05-19T14:33:57.645Z,1747665237.645 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-05-19T14:33:57.650Z,1747665237.650 [PitchRateCalculator] Loaded 2025-05-19T14:33:57.650Z,1747665237.650 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-05-19T14:33:57.659Z,1747665237.659 [SpeedCalculator] Loaded 2025-05-19T14:33:57.659Z,1747665237.659 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-05-19T14:33:57.664Z,1747665237.664 [YawRateCalculator] Loaded 2025-05-19T14:33:57.664Z,1747665237.664 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-05-19T14:33:57.683Z,1747665237.683 [ElevatorOffsetCalculator] Loaded 2025-05-19T14:33:57.684Z,1747665237.684 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-05-19T14:33:57.684Z,1747665237.684 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-05-19T14:33:57.685Z,1747665237.685 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-05-19T14:33:57.862Z,1747665237.862 [CANONSampler] Loaded 2025-05-19T14:33:57.862Z,1747665237.862 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2025-05-19T14:33:57.927Z,1747665237.927 [CTD_Seabird] Loaded 2025-05-19T14:33:57.927Z,1747665237.927 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-05-19T14:33:57.928Z,1747665237.928 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A964E0 2025-05-19T14:33:57.929Z,1747665237.929 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 928 2025-05-19T14:33:57.952Z,1747665237.952 [PAR_Licor] Loaded 2025-05-19T14:33:57.952Z,1747665237.952 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-05-19T14:33:57.998Z,1747665237.998 [WetLabsBB2FL] Loaded 2025-05-19T14:33:57.998Z,1747665237.998 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-05-19T14:33:57.999Z,1747665237.999 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC64E0 2025-05-19T14:33:57.999Z,1747665237.999 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 929 2025-05-19T14:33:57.000Z,1747665238.000 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-05-19T14:33:58.001Z,1747665238.001 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-05-19T14:33:58.049Z,1747665238.049 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-05-19T14:33:58.050Z,1747665238.050 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-05-19T14:33:58.506Z,1747665238.506 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-05-19T14:33:58.508Z,1747665238.508 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-05-19T14:33:58.708Z,1747665238.708 [SBIT](DEBUG): Construct Startup Built In Test. 2025-05-19T14:33:58.718Z,1747665238.718 [SBIT] Loaded 2025-05-19T14:33:58.718Z,1747665238.718 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-05-19T14:33:58.721Z,1747665238.721 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-05-19T14:33:58.734Z,1747665238.734 [IBIT] Loaded 2025-05-19T14:33:58.734Z,1747665238.734 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-05-19T14:33:58.740Z,1747665238.740 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-05-19T14:33:58.822Z,1747665238.822 [CBIT] Loaded 2025-05-19T14:33:58.823Z,1747665238.823 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-05-19T14:33:58.855Z,1747665238.855 [GFScanner] Loaded 2025-05-19T14:33:58.856Z,1747665238.856 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-05-19T14:33:58.856Z,1747665238.856 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-05-19T14:33:58.857Z,1747665238.857 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-05-19T14:33:59.024Z,1747665239.024 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-05-19T14:33:59.030Z,1747665239.030 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-05-19T14:33:59.033Z,1747665239.033 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-05-19T14:33:59.044Z,1747665239.044 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-05-19T14:33:59.045Z,1747665239.045 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0 2025-05-19T14:33:59.046Z,1747665239.046 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 930 2025-05-19T14:33:59.051Z,1747665239.051 [Supervisor](INFO): Main Thread ID is 833 2025-05-19T14:33:59.051Z,1747665239.051 [Supervisor](DEBUG): Running supervisor. 2025-05-19T14:33:59.052Z,1747665239.052 [CommandExec ThreadHandler](INFO): Handler Thread ID is 931 2025-05-19T14:33:59.053Z,1747665239.053 [CommandExec](INFO): Initializing the command executive. 2025-05-19T14:33:59.054Z,1747665239.054 [CommandLine ThreadHandler](INFO): Handler Thread ID is 932 2025-05-19T14:33:59.057Z,1747665239.057 [controlThread ThreadHandler](INFO): Handler Thread ID is 933 2025-05-19T14:33:59.057Z,1747665239.057 [controlThread](DEBUG): Initializing ControlThread 2025-05-19T14:33:59.058Z,1747665239.058 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-05-19T14:33:59.060Z,1747665239.060 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-05-19T14:33:59.060Z,1747665239.060 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-05-19T14:33:59.061Z,1747665239.061 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-05-19T14:33:59.062Z,1747665239.062 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-05-19T14:33:59.063Z,1747665239.063 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-05-19T14:33:59.065Z,1747665239.065 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-05-19T14:33:59.066Z,1747665239.066 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-05-19T14:33:59.066Z,1747665239.066 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-05-19T14:33:59.066Z,1747665239.066 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-05-19T14:33:59.067Z,1747665239.067 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-05-19T14:33:59.069Z,1747665239.069 [SBIT](INFO): Initialize SBIT Component. 2025-05-19T14:33:59.070Z,1747665239.070 [SBIT](IMPORTANT): git: 2025-05-16 2025-05-19T14:33:59.070Z,1747665239.070 [SBIT](INFO): git hash: 7cd925afbf924468d60d7bdc303f0aabfe74e3fc 2025-05-19T14:33:59.070Z,1747665239.070 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-05-19T14:33:59.071Z,1747665239.071 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2025-05-19T14:33:59.072Z,1747665239.072 [SBIT](INFO): Beginning SBIT in 68.000000 seconds. 2025-05-19T14:33:59.073Z,1747665239.073 [IBIT](INFO): Initialize IBIT Component. 2025-05-19T14:33:59.074Z,1747665239.074 [CBIT](DEBUG): Initialize CBIT Component. 2025-05-19T14:33:59.075Z,1747665239.075 [logger ThreadHandler](INFO): Handler Thread ID is 934 2025-05-19T14:33:59.085Z,1747665239.085 [CBIT](DEBUG): Initialized mux pins. 2025-05-19T14:33:59.085Z,1747665239.085 [CBIT](DEBUG): Initializing the watchdog timer. 2025-05-19T14:33:59.093Z,1747665239.093 [DAT ThreadHandler](INFO): Handler Thread ID is 935 2025-05-19T14:33:59.094Z,1747665239.094 [DAT](INFO): Powering up 2025-05-19T14:33:59.094Z,1747665239.094 [DAT](DEBUG): Initializing DAT. 2025-05-19T14:33:59.099Z,1747665239.099 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 937 2025-05-19T14:33:59.100Z,1747665239.100 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-05-19T14:33:59.109Z,1747665239.109 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-05-19T14:33:59.110Z,1747665239.110 [CBIT](DEBUG): Initializing heartbeat. 2025-05-19T14:33:59.111Z,1747665239.111 [Onboard ThreadHandler](INFO): Handler Thread ID is 938 2025-05-19T14:33:59.130Z,1747665239.130 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 939 2025-05-19T14:33:59.146Z,1747665239.146 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 940 2025-05-19T14:33:59.146Z,1747665239.146 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-05-19T14:33:59.149Z,1747665239.149 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 942 2025-05-19T14:33:59.154Z,1747665239.154 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 944 2025-05-19T14:33:59.155Z,1747665239.155 [WetLabsBB2FL](INFO): Powering up 2025-05-19T14:33:59.163Z,1747665239.163 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-05-19T14:33:59.163Z,1747665239.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-05-19T14:33:59.163Z,1747665239.163 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-05-19T14:33:59.163Z,1747665239.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-05-19T14:33:59.164Z,1747665239.164 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-05-19T14:33:59.164Z,1747665239.164 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-05-19T14:33:59.164Z,1747665239.164 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-05-19T14:33:59.164Z,1747665239.164 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-05-19T14:33:59.181Z,1747665239.181 [CBIT](DEBUG): Deactivating emergency mode. 2025-05-19T14:33:59.221Z,1747665239.221 [CBIT](DEBUG): Backplane powered. 2025-05-19T14:33:59.221Z,1747665239.221 [GFScanner](DEBUG): Initializing GFScanner 2025-05-19T14:33:59.222Z,1747665239.222 [GFScanner](DEBUG): Deactivating GF circuits. 2025-05-19T14:33:59.226Z,1747665239.226 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-05-19T14:33:59.227Z,1747665239.227 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-05-19T14:33:59.227Z,1747665239.227 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-05-19T14:33:59.232Z,1747665239.232 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-05-19T14:33:59.296Z,1747665239.296 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-05-19T14:33:59.301Z,1747665239.301 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-05-19T14:33:59.354Z,1747665239.354 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2025-05-19T14:33:59.355Z,1747665239.355 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-05-19T14:33:59.355Z,1747665239.355 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-05-19T14:33:59.358Z,1747665239.358 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-05-19T14:33:59.533Z,1747665239.533 [Radio_Surface](INFO): Powering up 2025-05-19T14:33:59.689Z,1747665239.689 [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-05-19T14:33:59.695Z,1747665239.695 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-05-19T14:33:59.696Z,1747665239.696 [Default:A.Wait](DEBUG): Construct Wait. 2025-05-19T14:33:59.715Z,1747665239.715 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-05-19T14:33:59.751Z,1747665239.751 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-05-19T14:33:59.778Z,1747665239.778 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-05-19T14:33:59.786Z,1747665239.786 [Default:E.Execute](DEBUG): Construct Execute. 2025-05-19T14:33:59.789Z,1747665239.789 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2025-05-19T14:33:59.812Z,1747665239.812 [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-05-19T14:33:59.833Z,1747665239.833 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-05-19T14:33:59.886Z,1747665239.886 [Depth_Keller](INFO): Initializing. 2025-05-19T14:33:59.887Z,1747665239.887 [Power24vConverter](INFO): Powering up. 2025-05-19T14:33:59.888Z,1747665239.888 [Sonardyne_Nano](INFO): Initializing. 2025-05-19T14:33:59.905Z,1747665239.905 [CANONSampler](INFO): Powering down 2025-05-19T14:33:59.933Z,1747665239.933 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-05-19T14:33:59.982Z,1747665239.982 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-05-19T14:33:59.986Z,1747665239.986 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-05-19T14:33:59.987Z,1747665239.987 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-05-19T14:34:00.045Z,1747665240.045 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-05-19T14:34:00.046Z,1747665240.046 [MassServo](DEBUG): Initializing EZServoServo. 2025-05-19T14:34:00.048Z,1747665240.048 [MassServo](DEBUG): Initializing MassServo. 2025-05-19T14:34:00.048Z,1747665240.048 [RudderServo](DEBUG): Initializing EZServoServo. 2025-05-19T14:34:00.059Z,1747665240.059 [RudderServo](DEBUG): Initializing RudderServo. 2025-05-19T14:34:00.060Z,1747665240.060 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-05-19T14:34:00.070Z,1747665240.070 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-05-19T14:34:01.261Z,1747665241.261 [WetLabsBB2FL](INFO): Powering down 2025-05-19T14:34:01.843Z,1747665241.843 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-05-19T14:34:03.130Z,1747665243.130 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2025-05-19T14:34:03.489Z,1747665243.489 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-05-19T14:34:05.726Z,1747665245.726 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-05-19T14:34:08.102Z,1747665248.102 [CommandExec](IMPORTANT): got command strobe off 2025-05-19T14:34:08.103Z,1747665248.103 [CommandExec](IMPORTANT): Deactivating strobe 2025-05-19T14:34:11.694Z,1747665251.694 [DAT](INFO): DAT read: 2025-05-19T14:34:11.695Z,1747665251.695 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-05-19T14:34:13.206Z,1747665253.206 [DAT](INFO): DAT read: MF Frequency Band 2025-05-19T14:34:13.207Z,1747665253.207 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-05-19T14:34:13.208Z,1747665253.208 [DAT](INFO): DAT read: May 19 2025 14:32:46 2025-05-19T14:34:14.214Z,1747665254.214 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-05-19T14:34:14.215Z,1747665254.215 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-05-19T14:34:14.216Z,1747665254.216 [DAT](INFO): commRate: 1200 2025-05-19T14:34:16.282Z,1747665256.282 [DAT](INFO): entering command mode 2025-05-19T14:34:16.482Z,1747665256.482 [DAT](INFO): DAT read: 2025-05-19T14:34:16.482Z,1747665256.482 [DAT](INFO): DAT read: user:1> 2025-05-19T14:34:16.483Z,1747665256.483 [DAT](INFO): setting verbose to 3 2025-05-19T14:34:16.734Z,1747665256.734 [DAT](INFO): DAT read: user:1> 2025-05-19T14:34:16.735Z,1747665256.735 [DAT](INFO): DAT read: Verbose | 3 2025-05-19T14:34:16.735Z,1747665256.735 [DAT](INFO): set verbose to 3 2025-05-19T14:34:16.736Z,1747665256.736 [DAT](INFO): setting DatVerbose to 27440 2025-05-19T14:34:16.986Z,1747665256.986 [DAT](INFO): DAT read: user:2> 2025-05-19T14:34:16.987Z,1747665256.987 [DAT](INFO): DAT read: DatVerbose | 27440 2025-05-19T14:34:16.987Z,1747665256.987 [DAT](INFO): set DatVerbose to 27440 2025-05-19T14:34:16.987Z,1747665256.987 [DAT](INFO): setting transmit power to 8 2025-05-19T14:34:17.238Z,1747665257.238 [DAT](INFO): DAT read: user:3> 2025-05-19T14:34:17.239Z,1747665257.239 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-05-19T14:34:17.239Z,1747665257.239 [DAT](INFO): set transmit power to 8 2025-05-19T14:34:17.239Z,1747665257.239 [DAT](INFO): setting local address to 8 2025-05-19T14:34:17.490Z,1747665257.490 [DAT](INFO): DAT read: user:4> 2025-05-19T14:34:17.491Z,1747665257.491 [DAT](INFO): DAT read: LocalAddr | 8 2025-05-19T14:34:17.491Z,1747665257.491 [DAT](INFO): set local address to 8 2025-05-19T14:34:17.492Z,1747665257.492 [DAT](INFO): Setting time to: 14:34:17 And date to:5/19/2025 2025-05-19T14:34:17.742Z,1747665257.742 [DAT](INFO): DAT read: user:5> 2025-05-19T14:34:17.743Z,1747665257.743 [DAT](INFO): DAT read: Mon May 19, 2025 14:34:17 2025-05-19T14:34:17.743Z,1747665257.743 [DAT](INFO): Local DAT time set to Mon May 19, 2025 14:34:17 2025-05-19T14:34:27.715Z,1747665267.715 [NAL9602](INFO): Powering up NAL9602 2025-05-19T14:34:34.542Z,1747665274.542 [CommandExec](IMPORTANT): got command strobe off 2025-05-19T14:34:34.543Z,1747665274.543 [CommandExec](IMPORTANT): Deactivating strobe 2025-05-19T14:34:38.623Z,1747665278.623 [NAL9602](INFO): NAL9602 initialized 2025-05-19T14:34:49.546Z,1747665289.546 [CommandExec](IMPORTANT): got command strobe off 2025-05-19T14:34:49.546Z,1747665289.546 [CommandExec](IMPORTANT): Deactivating strobe 2025-05-19T14:34:52.258Z,1747665292.258 [CommandExec](IMPORTANT): got command strobe off 2025-05-19T14:34:52.258Z,1747665292.258 [CommandExec](IMPORTANT): Deactivating strobe 2025-05-19T14:35:05.293Z,1747665305.293 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:35:07.771Z,1747665307.771 [SBIT](IMPORTANT): Beginning Startup BIT 2025-05-19T14:35:07.776Z,1747665307.776 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-05-19T14:35:12.258Z,1747665312.258 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002971 CHAN A1 (24V): 0.000628 CHAN A2 (12V): -0.001714 CHAN A3 (5V): -0.001175 CHAN B0 (3.3V): -0.000027 CHAN B1 (3.15aV): -0.000267 CHAN B2 (3.15bV): -0.000396 CHAN B3 (GND): -0.000471 OPEN: -0.000448 Full Scale: +/- 1 mA 2025-05-19T14:35:16.597Z,1747665316.597 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:35:27.908Z,1747665327.908 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:35:39.623Z,1747665339.623 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:35:50.971Z,1747665350.971 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:36:01.496Z,1747665361.496 [SBIT](IMPORTANT): SBIT PASSED 2025-05-19T14:36:01.496Z,1747665361.496 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-05-19T14:36:01.497Z,1747665361.497 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter; 2025-05-19T14:36:01.497Z,1747665361.497 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter; 2025-05-19T14:36:01.497Z,1747665361.497 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=309.007703 cubic_centimeter; 2025-05-19T14:36:01.497Z,1747665361.497 [SBIT](IMPORTANT): VerticalControl.massDefault=12.116547 millimeter; 2025-05-19T14:36:01.922Z,1747665361.922 [MissionManager](IMPORTANT): Started mission Startup 2025-05-19T14:36:01.923Z,1747665361.923 [Startup] Running Loop=1 2025-05-19T14:36:01.923Z,1747665361.923 [Startup](DEBUG): Aggregate::initialize Startup 2025-05-19T14:36:01.923Z,1747665361.923 [Startup:A.GoToSurface] Running Loop=1 2025-05-19T14:36:01.923Z,1747665361.923 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-05-19T14:36:01.923Z,1747665361.923 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-05-19T14:36:01.924Z,1747665361.924 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-05-19T14:36:01.924Z,1747665361.924 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-05-19T14:36:01.924Z,1747665361.924 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-05-19T14:36:01.925Z,1747665361.925 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-05-19T14:36:01.926Z,1747665361.926 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-05-19T14:36:01.927Z,1747665361.927 [Startup:StartupSatComms] Running Loop=1 2025-05-19T14:36:01.927Z,1747665361.927 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-05-19T14:36:01.927Z,1747665361.927 [Startup:StartupSatComms:A] Running Loop=1 2025-05-19T14:36:02.283Z,1747665362.283 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:36:02.323Z,1747665362.323 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-05-19T14:36:13.609Z,1747665373.609 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:36:25.311Z,1747665385.311 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:36:34.504Z,1747665394.504 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004981 2025-05-19T14:36:59.305Z,1747665419.305 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-05-19T14:36:59.305Z,1747665419.305 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:36:59.467Z,1747665419.467 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:36:59.841Z,1747665419.841 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:36:59.841Z,1747665419.841 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-05-19T14:37:02.107Z,1747665422.107 [Startup:StartupSatComms:A](INFO): Timed out from 2025-05-19T14:36:01.9Z 2025-05-19T14:37:02.108Z,1747665422.108 [Startup:StartupSatComms:A] Stopped 2025-05-19T14:37:02.108Z,1747665422.108 [Startup:StartupSatComms:B] Running Loop=1 2025-05-19T14:37:02.515Z,1747665422.515 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-05-19T14:37:07.018Z,1747665427.018 [CommandExec](IMPORTANT): got command failComponent 2025-05-19T14:37:07.018Z,1747665427.018 [CommandExec](IMPORTANT): Failed components: 2025-05-19T14:37:07.018Z,1747665427.018 [CommandExec](IMPORTANT): No failed Components. 2025-05-19T14:37:12.353Z,1747665432.353 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250519T142939/Courier0000.lzma 2025-05-19T14:37:13.355Z,1747665433.355 [DataOverHttps](INFO): Moved sent file to Logs/20250519T142939/Courier0000.lzma.bak 2025-05-19T14:37:13.355Z,1747665433.355 [DataOverHttps](INFO): SBD MOMSN=24919830 2025-05-19T14:37:15.693Z,1747665435.693 [CommandExec](IMPORTANT): got command get Onboard.Pressure pound_per_square_inch 2025-05-19T14:37:15.694Z,1747665435.694 [CommandExec](IMPORTANT): Onboard.Pressure 9.451601 psi 2025-05-19T14:37:28.648Z,1747665448.648 [CommandExec](IMPORTANT): got command get Onboard.Humidity 2025-05-19T14:37:28.649Z,1747665448.649 [CommandExec](IMPORTANT): Onboard.Humidity 17.146868 % 2025-05-19T14:37:30.734Z,1747665450.734 [CommandExec](IMPORTANT): got command failComponent 2025-05-19T14:37:30.734Z,1747665450.734 [CommandExec](IMPORTANT): Failed components: 2025-05-19T14:37:30.734Z,1747665450.734 [CommandExec](IMPORTANT): No failed Components. 2025-05-19T14:37:31.209Z,1747665451.209 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250519T143346/Courier0000.lzma 2025-05-19T14:37:32.211Z,1747665452.211 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0000.lzma.bak 2025-05-19T14:37:32.211Z,1747665452.211 [DataOverHttps](INFO): SBD MOMSN=24919833 2025-05-19T14:37:48.276Z,1747665468.276 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250519T142939/Express0001.lzma 2025-05-19T14:37:49.280Z,1747665469.280 [DataOverHttps](INFO): Moved sent file to Logs/20250519T142939/Express0001.lzma.bak 2025-05-19T14:37:49.280Z,1747665469.280 [DataOverHttps](INFO): SBD MOMSN=24919836 2025-05-19T14:38:02.479Z,1747665482.480 [Startup:StartupSatComms:B](INFO): Timed out from 2025-05-19T14:37:02.1Z 2025-05-19T14:38:02.480Z,1747665482.480 [Startup:StartupSatComms:B] Stopped 2025-05-19T14:38:02.480Z,1747665482.480 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-05-19T14:38:02.480Z,1747665482.480 [Startup:StartupSatComms] Stopped 2025-05-19T14:38:02.480Z,1747665482.480 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-05-19T14:38:02.485Z,1747665482.485 [Startup](INFO): Completed Startup 2025-05-19T14:38:02.485Z,1747665482.485 [MissionManager](INFO): Startup is completed. 2025-05-19T14:38:02.485Z,1747665482.485 [MissionManager](INFO): Uninitializing Mission Startup 2025-05-19T14:38:02.485Z,1747665482.485 [Startup] Stopped 2025-05-19T14:38:02.486Z,1747665482.486 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-05-19T14:38:02.486Z,1747665482.486 [Startup:A.GoToSurface] Stopped 2025-05-19T14:38:02.486Z,1747665482.486 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-05-19T14:38:02.898Z,1747665482.898 [MissionManager](IMPORTANT): Started mission Default 2025-05-19T14:38:02.898Z,1747665482.898 [Default] Running Loop=1 2025-05-19T14:38:02.898Z,1747665482.898 [Default](DEBUG): Aggregate::initialize Default 2025-05-19T14:38:02.898Z,1747665482.898 [Default:B.GoToSurface] Running Loop=1 2025-05-19T14:38:02.898Z,1747665482.898 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-05-19T14:38:02.899Z,1747665482.899 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-05-19T14:38:02.899Z,1747665482.899 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-05-19T14:38:02.899Z,1747665482.899 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-05-19T14:38:02.899Z,1747665482.899 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-05-19T14:38:02.900Z,1747665482.900 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-05-19T14:38:02.900Z,1747665482.900 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-05-19T14:38:02.900Z,1747665482.900 [Default:A.Wait] Running Loop=1 2025-05-19T14:38:02.900Z,1747665482.900 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-05-19T14:38:05.519Z,1747665485.519 [DataOverHttps](INFO): Sending 881 bytes from file Logs/20250519T143346/Express0001.lzma 2025-05-19T14:38:06.519Z,1747665486.519 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0001.lzma.bak 2025-05-19T14:38:06.519Z,1747665486.519 [DataOverHttps](INFO): SBD MOMSN=24919838 2025-05-19T14:38:16.236Z,1747665496.236 [Default:A.Wait](INFO): Done Waiting. 2025-05-19T14:38:16.236Z,1747665496.236 [Default:A.Wait] Stopped 2025-05-19T14:38:16.236Z,1747665496.236 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T14:38:16.647Z,1747665496.647 [Default:CheckIn] Running Loop=1 2025-05-19T14:38:16.648Z,1747665496.648 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T14:38:16.648Z,1747665496.648 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T14:38:17.059Z,1747665497.059 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-05-19T14:38:57.812Z,1747665537.812 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:39:11.547Z,1747665551.547 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:39:24.880Z,1747665564.880 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:39:38.615Z,1747665578.615 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:39:41.446Z,1747665581.446 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-05-19T14:39:52.755Z,1747665592.755 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:40:00.522Z,1747665600.522 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-05-19T14:40:00.522Z,1747665600.522 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:40:00.685Z,1747665600.685 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:40:01.019Z,1747665601.019 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:40:01.019Z,1747665601.019 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-05-19T14:40:06.103Z,1747665606.103 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:40:19.441Z,1747665619.441 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:40:32.772Z,1747665632.772 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:40:45.296Z,1747665645.296 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:40:59.031Z,1747665659.031 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:41:12.368Z,1747665672.368 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:43:01.463Z,1747665781.463 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-05-19T14:43:01.463Z,1747665781.463 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:43:01.626Z,1747665781.626 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:43:02.033Z,1747665782.033 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:43:02.033Z,1747665782.033 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-05-19T14:43:16.845Z,1747665796.845 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-19T14:38:16.6Z 2025-05-19T14:43:16.845Z,1747665796.845 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T14:43:16.864Z,1747665796.864 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T14:43:17.242Z,1747665797.242 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-05-19T14:43:20.228Z,1747665800.228 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250519T143346/Courier0004.lzma 2025-05-19T14:43:21.231Z,1747665801.231 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0004.lzma.bak 2025-05-19T14:43:21.231Z,1747665801.231 [DataOverHttps](INFO): SBD MOMSN=24919876 2025-05-19T14:43:37.271Z,1747665817.271 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20250519T143346/Express0005.lzma 2025-05-19T14:43:38.271Z,1747665818.271 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0005.lzma.bak 2025-05-19T14:43:38.271Z,1747665818.271 [DataOverHttps](INFO): SBD MOMSN=24919925 2025-05-19T14:43:39.625Z,1747665819.625 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T14:43:39.625Z,1747665819.625 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T14:43:39.625Z,1747665819.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T14:44:40.607Z,1747665880.607 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-05-19T14:44:40.607Z,1747665880.607 [NAL9602] Data Fault, FailCount= 1 2025-05-19T14:44:40.607Z,1747665880.607 [NAL9602](ERROR): Data Fault 2025-05-19T14:44:40.797Z,1747665880.797 [CBIT](ERROR): Data Fault in component: NAL9602 2025-05-19T14:44:40.998Z,1747665880.998 [NAL9602](INFO): Powering down 2025-05-19T14:44:41.961Z,1747665881.961 [CBIT](INFO): Clearing failed state for component NAL9602 2025-05-19T14:44:41.961Z,1747665881.961 [NAL9602] No Fault, FailCount= 1 2025-05-19T14:45:11.298Z,1747665911.298 [NAL9602](INFO): Powering up NAL9602 2025-05-19T14:45:22.211Z,1747665922.211 [NAL9602](INFO): NAL9602 initialized 2025-05-19T14:46:02.645Z,1747665962.645 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-05-19T14:46:02.645Z,1747665962.645 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:46:02.785Z,1747665962.785 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:46:03.185Z,1747665963.185 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:46:03.185Z,1747665963.185 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-05-19T14:47:35.622Z,1747666055.622 [CommandExec](IMPORTANT): got command burn on 2025-05-19T14:47:35.622Z,1747666055.622 [CommandExec](IMPORTANT): Activating dropweight wire 2025-05-19T14:48:36.947Z,1747666116.947 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:48:40.217Z,1747666120.217 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T14:48:40.217Z,1747666120.217 [Default:CheckIn:C.Wait] Stopped 2025-05-19T14:48:40.217Z,1747666120.217 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T14:48:40.218Z,1747666120.218 [Default:CheckIn:D] Running Loop=1 2025-05-19T14:48:40.631Z,1747666120.631 [Default:CheckIn:D] Stopped 2025-05-19T14:48:40.632Z,1747666120.632 [Default:CheckIn:E] Running Loop=1 2025-05-19T14:48:41.023Z,1747666121.023 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.628890 min 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn:E] Stopped 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn] Stopped 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn](INFO): Running loop #2 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn] Running Loop=2 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T14:48:41.024Z,1747666121.024 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T14:48:49.905Z,1747666129.905 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:48:56.574Z,1747666136.574 [CommandExec](IMPORTANT): got command burn off 2025-05-19T14:48:56.574Z,1747666136.574 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-05-19T14:49:03.207Z,1747666143.207 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:49:03.663Z,1747666143.663 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-05-19T14:49:03.663Z,1747666143.663 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:49:03.807Z,1747666143.807 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:49:04.210Z,1747666144.210 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:49:04.210Z,1747666144.210 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-05-19T14:49:15.731Z,1747666155.731 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:49:29.064Z,1747666169.064 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:49:42.799Z,1747666182.799 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:49:56.940Z,1747666196.940 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:50:10.679Z,1747666210.679 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:50:24.007Z,1747666224.007 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:50:37.340Z,1747666237.340 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:50:51.077Z,1747666251.077 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:52:04.634Z,1747666324.634 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-05-19T14:52:04.634Z,1747666324.634 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:52:04.666Z,1747666324.666 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:52:05.077Z,1747666325.077 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:52:05.078Z,1747666325.078 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-05-19T14:53:41.298Z,1747666421.298 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-19T14:48:41.0Z 2025-05-19T14:53:41.298Z,1747666421.298 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T14:53:41.299Z,1747666421.299 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T14:53:48.504Z,1747666428.504 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250519T143346/Courier0007.lzma 2025-05-19T14:53:49.507Z,1747666429.507 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0007.lzma.bak 2025-05-19T14:53:49.507Z,1747666429.507 [DataOverHttps](INFO): SBD MOMSN=24919953 2025-05-19T14:54:05.213Z,1747666445.213 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20250519T143346/Express0008.lzma 2025-05-19T14:54:06.215Z,1747666446.215 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0008.lzma.bak 2025-05-19T14:54:06.215Z,1747666446.215 [DataOverHttps](INFO): SBD MOMSN=24919994 2025-05-19T14:54:07.563Z,1747666447.563 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T14:54:07.563Z,1747666447.563 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T14:54:07.563Z,1747666447.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T14:55:05.715Z,1747666505.715 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2025-05-19T14:55:05.715Z,1747666505.715 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:55:05.726Z,1747666505.726 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:55:06.136Z,1747666506.136 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:55:06.136Z,1747666506.136 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2025-05-19T14:55:24.291Z,1747666524.291 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-05-19T14:55:24.291Z,1747666524.291 [NAL9602] Data Fault, FailCount= 2 2025-05-19T14:55:24.291Z,1747666524.291 [NAL9602](ERROR): Data Fault 2025-05-19T14:55:24.337Z,1747666524.337 [CBIT](ERROR): Data Fault in component: NAL9602 2025-05-19T14:55:24.694Z,1747666524.694 [NAL9602](INFO): Powering down 2025-05-19T14:55:25.541Z,1747666525.541 [CBIT](INFO): Clearing failed state for component NAL9602 2025-05-19T14:55:25.541Z,1747666525.541 [NAL9602] No Fault, FailCount= 2 2025-05-19T14:55:55.013Z,1747666555.013 [NAL9602](INFO): Powering up NAL9602 2025-05-19T14:56:05.907Z,1747666565.907 [NAL9602](INFO): NAL9602 initialized 2025-05-19T14:58:06.723Z,1747666686.723 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2025-05-19T14:58:06.723Z,1747666686.723 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T14:58:06.734Z,1747666686.734 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T14:58:07.143Z,1747666687.143 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T14:58:07.144Z,1747666687.144 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2025-05-19T14:58:23.264Z,1747666703.264 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:58:36.596Z,1747666716.596 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:58:49.928Z,1747666729.928 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:59:03.263Z,1747666743.263 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:59:08.147Z,1747666748.147 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T14:59:08.147Z,1747666748.147 [Default:CheckIn:C.Wait] Stopped 2025-05-19T14:59:08.147Z,1747666748.147 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T14:59:08.147Z,1747666748.147 [Default:CheckIn:D] Running Loop=1 2025-05-19T14:59:08.543Z,1747666748.543 [Default:CheckIn:D] Stopped 2025-05-19T14:59:08.543Z,1747666748.543 [Default:CheckIn:E] Running Loop=1 2025-05-19T14:59:08.931Z,1747666748.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.094086 min 2025-05-19T14:59:08.931Z,1747666748.931 [Default:CheckIn:E] Stopped 2025-05-19T14:59:08.931Z,1747666748.931 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T14:59:08.931Z,1747666748.931 [Default:CheckIn] Stopped 2025-05-19T14:59:08.931Z,1747666748.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T14:59:08.931Z,1747666748.931 [Default:CheckIn](INFO): Running loop #3 2025-05-19T14:59:08.931Z,1747666748.931 [Default:CheckIn] Running Loop=3 2025-05-19T14:59:08.932Z,1747666748.932 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T14:59:08.932Z,1747666748.932 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T14:59:16.596Z,1747666756.596 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:59:29.923Z,1747666769.923 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:59:43.269Z,1747666783.269 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T14:59:56.991Z,1747666796.991 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T15:00:10.325Z,1747666810.325 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T15:00:24.463Z,1747666824.463 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T15:00:38.199Z,1747666838.199 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T15:01:07.720Z,1747666867.720 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2025-05-19T15:01:07.720Z,1747666867.720 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-05-19T15:01:07.731Z,1747666867.731 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-05-19T15:01:08.152Z,1747666868.152 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-05-19T15:01:08.152Z,1747666868.152 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2025-05-19T15:03:31.991Z,1747667011.991 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150330.00,A,3648.16649,N,12147.26496,W,3.285,121.74,190525,,,A*74 2025-05-19T15:03:31.995Z,1747667011.995 [NAL9602](INFO): GPS fix at 20250519T150330: (36.802775, -121.787749) 2025-05-19T15:03:32.007Z,1747667012.007 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:03:32.007Z,1747667012.007 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:03:41.773Z,1747667021.773 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20250519T143346/Courier0010.lzma 2025-05-19T15:03:42.775Z,1747667022.775 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0010.lzma.bak 2025-05-19T15:03:42.775Z,1747667022.775 [DataOverHttps](INFO): SBD MOMSN=24920014 2025-05-19T15:03:59.714Z,1747667039.714 [DataOverHttps](INFO): Sending 374 bytes from file Logs/20250519T143346/Express0011.lzma 2025-05-19T15:04:00.715Z,1747667040.715 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0011.lzma.bak 2025-05-19T15:04:00.715Z,1747667040.715 [DataOverHttps](INFO): SBD MOMSN=24920018 2025-05-19T15:04:01.906Z,1747667041.906 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:04:01.906Z,1747667041.906 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:04:01.906Z,1747667041.906 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:04:04.314Z,1747667044.314 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:05:00.070Z,1747667100.070 [BPC1](ERROR): Battery stick #31 (s/n: 029D) reported TERMINATE_CHARGE_ALARM. Status code: 0x40C0. 2025-05-19T15:05:00.070Z,1747667100.070 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2025-05-19T15:05:00.074Z,1747667100.074 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2025-05-19T15:06:42.158Z,1747667202.158 [DataOverHttps](IMPORTANT): SBD MTMSN=20250519T150641 2025-05-19T15:06:51.501Z,1747667211.501 [DataOverHttps](INFO): Received command: ibit 2025-05-19T15:06:51.503Z,1747667211.503 [CommandExec](IMPORTANT): got command ibit 2025-05-19T15:06:51.625Z,1747667211.625 [IBIT](IMPORTANT): Beginning Initiated BIT 2025-05-19T15:06:51.625Z,1747667211.625 [IBIT](IMPORTANT): Beginning control surface checks. 2025-05-19T15:06:51.637Z,1747667211.637 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-05-19T15:06:53.234Z,1747667213.234 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150652.00,A,3648.13838,N,12147.23048,W,0.136,69.93,190525,,,A*46 2025-05-19T15:06:53.237Z,1747667213.237 [NAL9602](INFO): GPS fix at 20250519T150652: (36.802306, -121.787175) 2025-05-19T15:06:56.280Z,1747667216.280 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.001654 CHAN A1 (24V): 0.000724 CHAN A2 (12V): -0.002244 CHAN A3 (5V): -0.001807 CHAN B0 (3.3V): 0.000166 CHAN B1 (3.15aV): -0.000417 CHAN B2 (3.15bV): -0.000532 CHAN B3 (GND): 0.000214 OPEN: -0.000371 Full Scale: +/- 1 mA 2025-05-19T15:07:07.370Z,1747667227.370 [NAL9602](INFO): SBD MO Status=0, MOMSN=63128, MT Status=0, MTMSN=0 2025-05-19T15:07:07.370Z,1747667227.370 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:07:08.587Z,1747667228.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150707.00,A,3648.13855,N,12147.23034,W,0.136,69.93,190525,,,A*47 2025-05-19T15:07:08.590Z,1747667228.590 [NAL9602](INFO): GPS fix at 20250519T150707: (36.802309, -121.787172) 2025-05-19T15:07:11.001Z,1747667231.001 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150710.00,A,3648.13865,N,12147.23031,W,0.117,69.93,190525,,,A*44 2025-05-19T15:07:11.003Z,1747667231.003 [NAL9602](INFO): GPS fix at 20250519T150710: (36.802311, -121.787172) 2025-05-19T15:07:13.828Z,1747667233.828 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150713.00,A,3648.13868,N,12147.23020,W,0.039,69.93,190525,,,A*47 2025-05-19T15:07:13.830Z,1747667233.830 [NAL9602](INFO): GPS fix at 20250519T150713: (36.802311, -121.787170) 2025-05-19T15:07:17.060Z,1747667237.060 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150716.00,A,3648.13876,N,12147.23014,W,0.136,69.93,190525,,,A*44 2025-05-19T15:07:17.063Z,1747667237.063 [NAL9602](INFO): GPS fix at 20250519T150716: (36.802313, -121.787169) 2025-05-19T15:07:19.896Z,1747667239.896 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150719.00,A,3648.13887,N,12147.23013,W,0.097,69.93,190525,,,A*48 2025-05-19T15:07:19.898Z,1747667239.898 [NAL9602](INFO): GPS fix at 20250519T150719: (36.802315, -121.787169) 2025-05-19T15:07:23.124Z,1747667243.124 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150722.00,A,3648.13898,N,12147.23006,W,0.097,69.93,190525,,,A*4A 2025-05-19T15:07:23.126Z,1747667243.126 [NAL9602](INFO): GPS fix at 20250519T150722: (36.802316, -121.787168) 2025-05-19T15:07:25.958Z,1747667245.958 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150725.00,A,3648.13900,N,12147.22962,W,0.078,69.93,190525,,,A*46 2025-05-19T15:07:25.960Z,1747667245.960 [NAL9602](INFO): GPS fix at 20250519T150725: (36.802317, -121.787160) 2025-05-19T15:07:28.778Z,1747667248.778 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150728.00,A,3648.13898,N,12147.22930,W,0.156,69.93,190525,,,A*41 2025-05-19T15:07:28.780Z,1747667248.780 [NAL9602](INFO): GPS fix at 20250519T150728: (36.802316, -121.787155) 2025-05-19T15:07:32.014Z,1747667252.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150731.00,A,3648.13901,N,12147.22924,W,0.175,69.93,190525,,,D*49 2025-05-19T15:07:32.016Z,1747667252.016 [NAL9602](INFO): GPS fix at 20250519T150731: (36.802317, -121.787154) 2025-05-19T15:07:34.837Z,1747667254.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150734.00,A,3648.13904,N,12147.22941,W,0.039,69.93,190525,,,D*43 2025-05-19T15:07:34.839Z,1747667254.839 [NAL9602](INFO): GPS fix at 20250519T150734: (36.802317, -121.787157) 2025-05-19T15:07:37.708Z,1747667257.708 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802319 Longitude: -121.787155 2025-05-19T15:07:38.072Z,1747667258.072 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150737.00,A,3648.13903,N,12147.22949,W,0.078,69.93,190525,,,D*4A 2025-05-19T15:07:38.074Z,1747667258.074 [NAL9602](INFO): GPS fix at 20250519T150737: (36.802317, -121.787158) 2025-05-19T15:07:38.091Z,1747667258.091 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.650999 2025-05-19T15:07:38.091Z,1747667258.091 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2025-05-19T15:07:38.091Z,1747667258.091 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2025-05-19T15:07:38.511Z,1747667258.511 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2025-05-19T15:07:38.511Z,1747667258.511 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2025-05-19T15:07:38.512Z,1747667258.512 [IBIT](IMPORTANT): Pressure:9.467669 PSI 2025-05-19T15:07:38.512Z,1747667258.512 [IBIT](IMPORTANT): Humidity:17.018679 % 2025-05-19T15:07:38.901Z,1747667258.901 [IBIT](IMPORTANT): Vehicle Pitch:-0.607003 degrees 2025-05-19T15:07:38.901Z,1747667258.901 [IBIT](IMPORTANT): Vehicle Roll:-4.147582 degrees 2025-05-19T15:07:38.902Z,1747667258.902 [IBIT](IMPORTANT): Vehicle Heading:9.689334 degrees 2025-05-19T15:07:39.328Z,1747667259.328 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2025-05-19T15:07:39.328Z,1747667259.328 [IBIT](IMPORTANT): buoyancyNeutral: 309.007690 cc 2025-05-19T15:07:39.333Z,1747667259.333 [IBIT](IMPORTANT): massDefault: 1.211655 cm 2025-05-19T15:07:39.333Z,1747667259.333 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2025-05-19T15:07:39.334Z,1747667259.334 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2025-05-19T15:07:39.334Z,1747667259.334 [IBIT](IMPORTANT): IBIT PASSED 2025-05-19T15:08:10.386Z,1747667290.386 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:09:02.635Z,1747667342.635 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:09:02.635Z,1747667342.635 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:09:02.635Z,1747667342.635 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:09:02.636Z,1747667342.636 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:09:03.033Z,1747667343.033 [Default:CheckIn:D] Stopped 2025-05-19T15:09:03.033Z,1747667343.033 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:09:03.436Z,1747667343.436 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.002246 min 2025-05-19T15:09:03.436Z,1747667343.436 [Default:CheckIn:E] Stopped 2025-05-19T15:09:03.436Z,1747667343.436 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:09:03.437Z,1747667343.437 [Default:CheckIn] Stopped 2025-05-19T15:09:03.437Z,1747667343.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:09:03.437Z,1747667343.437 [Default:CheckIn](INFO): Running loop #4 2025-05-19T15:09:03.437Z,1747667343.437 [Default:CheckIn] Running Loop=4 2025-05-19T15:09:03.437Z,1747667343.437 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:09:03.437Z,1747667343.437 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:09:05.451Z,1747667345.451 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150904.00,A,3648.14138,N,12147.23192,W,0.233,69.93,190525,,,D*41 2025-05-19T15:09:05.453Z,1747667345.453 [NAL9602](INFO): GPS fix at 20250519T150904: (36.802356, -121.787199) 2025-05-19T15:09:05.465Z,1747667345.465 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:09:05.465Z,1747667345.465 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:09:13.405Z,1747667353.405 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250519T143346/Courier0013.lzma 2025-05-19T15:09:14.407Z,1747667354.407 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0013.lzma.bak 2025-05-19T15:09:14.407Z,1747667354.407 [DataOverHttps](INFO): SBD MOMSN=24920076 2025-05-19T15:09:15.568Z,1747667355.568 [NAL9602](INFO): SBD MO Status=0, MOMSN=63129, MT Status=0, MTMSN=0 2025-05-19T15:09:15.569Z,1747667355.569 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:09:30.815Z,1747667370.815 [DataOverHttps](INFO): Sending 1034 bytes from file Logs/20250519T143346/Express0014.lzma 2025-05-19T15:09:31.815Z,1747667371.815 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0014.lzma.bak 2025-05-19T15:09:31.815Z,1747667371.815 [DataOverHttps](INFO): SBD MOMSN=24920079 2025-05-19T15:09:46.274Z,1747667386.274 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:09:48.509Z,1747667388.509 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250519T143346/Express0017.lzma 2025-05-19T15:09:49.511Z,1747667389.511 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0017.lzma.bak 2025-05-19T15:09:49.511Z,1747667389.511 [DataOverHttps](INFO): SBD MOMSN=24920117 2025-05-19T15:09:50.724Z,1747667390.724 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:09:50.725Z,1747667390.725 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:09:50.725Z,1747667390.725 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:14:51.388Z,1747667691.388 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:14:51.388Z,1747667691.388 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:14:51.388Z,1747667691.388 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:14:51.388Z,1747667691.388 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:14:51.782Z,1747667691.782 [Default:CheckIn:D] Stopped 2025-05-19T15:14:51.782Z,1747667691.782 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:14:52.189Z,1747667692.189 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.814738 min 2025-05-19T15:14:52.189Z,1747667692.189 [Default:CheckIn:E] Stopped 2025-05-19T15:14:52.189Z,1747667692.189 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:14:52.189Z,1747667692.189 [Default:CheckIn] Stopped 2025-05-19T15:14:52.189Z,1747667692.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:14:52.189Z,1747667692.189 [Default:CheckIn](INFO): Running loop #5 2025-05-19T15:14:52.190Z,1747667692.190 [Default:CheckIn] Running Loop=5 2025-05-19T15:14:52.190Z,1747667692.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:14:52.190Z,1747667692.190 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:14:54.188Z,1747667694.188 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151453.00,A,3648.13875,N,12147.23019,W,0.039,69.93,190525,,,D*42 2025-05-19T15:14:54.190Z,1747667694.190 [NAL9602](INFO): GPS fix at 20250519T151453: (36.802312, -121.787170) 2025-05-19T15:14:54.233Z,1747667694.233 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:14:54.234Z,1747667694.234 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:14:55.112Z,1747667695.112 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:14:55.112Z,1747667695.112 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:14:55.112Z,1747667695.112 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:15:18.916Z,1747667718.916 [NAL9602](INFO): SBD MO Status=2, MOMSN=63130, MT Status=2, MTMSN=0 2025-05-19T15:15:18.916Z,1747667718.916 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T15:15:33.864Z,1747667733.864 [NAL9602](INFO): SBD MO Status=2, MOMSN=63130, MT Status=2, MTMSN=0 2025-05-19T15:15:33.864Z,1747667733.864 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T15:15:54.064Z,1747667754.064 [NAL9602](INFO): SBD MO Status=0, MOMSN=63130, MT Status=0, MTMSN=0 2025-05-19T15:15:54.064Z,1747667754.064 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:16:24.766Z,1747667784.766 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:19:11.886Z,1747667951.886 [CommandExec](IMPORTANT): got command failComponent 2025-05-19T15:19:11.886Z,1747667951.886 [CommandExec](IMPORTANT): Failed components: 2025-05-19T15:19:11.886Z,1747667951.886 [CommandExec](IMPORTANT): No failed Components. 2025-05-19T15:19:15.422Z,1747667955.422 [CommandExec](IMPORTANT): got command failComponent 2025-05-19T15:19:15.422Z,1747667955.422 [CommandExec](IMPORTANT): Failed components: 2025-05-19T15:19:15.422Z,1747667955.422 [CommandExec](IMPORTANT): No failed Components. 2025-05-19T15:19:55.670Z,1747667995.670 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:19:55.670Z,1747667995.670 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:19:55.670Z,1747667995.670 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:19:55.671Z,1747667995.671 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:19:56.082Z,1747667996.082 [Default:CheckIn:D] Stopped 2025-05-19T15:19:56.082Z,1747667996.082 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:19:56.512Z,1747667996.512 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.886401 min 2025-05-19T15:19:56.512Z,1747667996.512 [Default:CheckIn:E] Stopped 2025-05-19T15:19:56.512Z,1747667996.512 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:19:56.512Z,1747667996.512 [Default:CheckIn] Stopped 2025-05-19T15:19:56.513Z,1747667996.513 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:19:56.513Z,1747667996.513 [Default:CheckIn](INFO): Running loop #6 2025-05-19T15:19:56.513Z,1747667996.513 [Default:CheckIn] Running Loop=6 2025-05-19T15:19:56.513Z,1747667996.513 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:19:56.513Z,1747667996.513 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:19:58.489Z,1747667998.489 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151957.00,A,3648.14091,N,12147.22823,W,0.019,69.93,190525,,,D*4C 2025-05-19T15:19:58.491Z,1747667998.491 [NAL9602](INFO): GPS fix at 20250519T151957: (36.802349, -121.787137) 2025-05-19T15:19:58.502Z,1747667998.502 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:19:58.502Z,1747667998.502 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:20:06.713Z,1747668006.713 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0019.lzma 2025-05-19T15:20:07.715Z,1747668007.715 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0019.lzma.bak 2025-05-19T15:20:07.715Z,1747668007.715 [DataOverHttps](INFO): SBD MOMSN=24920186 2025-05-19T15:20:13.436Z,1747668013.436 [NAL9602](INFO): SBD MO Status=0, MOMSN=63131, MT Status=0, MTMSN=0 2025-05-19T15:20:13.436Z,1747668013.436 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:20:26.985Z,1747668026.985 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0022.lzma 2025-05-19T15:20:27.987Z,1747668027.987 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0022.lzma.bak 2025-05-19T15:20:27.987Z,1747668027.987 [DataOverHttps](INFO): SBD MOMSN=24920189 2025-05-19T15:20:44.206Z,1747668044.206 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:20:44.425Z,1747668044.425 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0020.lzma 2025-05-19T15:20:45.427Z,1747668045.427 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0020.lzma.bak 2025-05-19T15:20:45.427Z,1747668045.427 [DataOverHttps](INFO): SBD MOMSN=24920195 2025-05-19T15:21:05.040Z,1747668065.040 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20250519T143346/Express0023.lzma 2025-05-19T15:21:06.023Z,1747668066.023 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0023.lzma.bak 2025-05-19T15:21:06.023Z,1747668066.023 [DataOverHttps](INFO): SBD MOMSN=24920201 2025-05-19T15:21:07.314Z,1747668067.314 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:21:07.314Z,1747668067.314 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:21:07.314Z,1747668067.314 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:26:07.932Z,1747668367.932 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:26:07.932Z,1747668367.932 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:26:07.932Z,1747668367.932 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:26:07.932Z,1747668367.932 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:26:08.338Z,1747668368.338 [Default:CheckIn:D] Stopped 2025-05-19T15:26:08.338Z,1747668368.338 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.090662 min 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn:E] Stopped 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn] Stopped 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn](INFO): Running loop #7 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn] Running Loop=7 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:26:08.743Z,1747668368.743 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:26:10.756Z,1747668370.756 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152610.00,A,3648.13989,N,12147.22328,W,0.058,69.93,190525,,,D*41 2025-05-19T15:26:10.759Z,1747668370.759 [NAL9602](INFO): GPS fix at 20250519T152610: (36.802332, -121.787055) 2025-05-19T15:26:10.771Z,1747668370.771 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:26:10.771Z,1747668370.771 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:26:11.572Z,1747668371.572 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:26:11.572Z,1747668371.572 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:26:11.572Z,1747668371.572 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:26:21.258Z,1747668381.258 [NAL9602](INFO): SBD MO Status=0, MOMSN=63132, MT Status=0, MTMSN=0 2025-05-19T15:26:21.258Z,1747668381.258 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:26:51.958Z,1747668411.958 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:31:12.356Z,1747668672.356 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:31:12.356Z,1747668672.356 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:31:12.356Z,1747668672.356 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:31:12.356Z,1747668672.356 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:31:12.752Z,1747668672.752 [Default:CheckIn:D] Stopped 2025-05-19T15:31:12.753Z,1747668672.753 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:31:13.157Z,1747668673.157 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.164237 min 2025-05-19T15:31:13.157Z,1747668673.157 [Default:CheckIn:E] Stopped 2025-05-19T15:31:13.157Z,1747668673.157 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:31:13.157Z,1747668673.157 [Default:CheckIn] Stopped 2025-05-19T15:31:13.157Z,1747668673.157 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:31:13.158Z,1747668673.158 [Default:CheckIn](INFO): Running loop #8 2025-05-19T15:31:13.158Z,1747668673.158 [Default:CheckIn] Running Loop=8 2025-05-19T15:31:13.158Z,1747668673.158 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:31:13.158Z,1747668673.158 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:31:15.170Z,1747668675.170 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153114.00,A,3648.14075,N,12147.22890,W,0.019,69.93,190525,,,D*43 2025-05-19T15:31:15.172Z,1747668675.172 [NAL9602](INFO): GPS fix at 20250519T153114: (36.802346, -121.787148) 2025-05-19T15:31:15.183Z,1747668675.183 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:31:15.183Z,1747668675.183 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:31:22.577Z,1747668682.577 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0025.lzma 2025-05-19T15:31:23.579Z,1747668683.579 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0025.lzma.bak 2025-05-19T15:31:23.579Z,1747668683.579 [DataOverHttps](INFO): SBD MOMSN=24920296 2025-05-19T15:31:35.772Z,1747668695.772 [NAL9602](INFO): SBD MO Status=0, MOMSN=63133, MT Status=0, MTMSN=0 2025-05-19T15:31:35.772Z,1747668695.772 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:31:40.057Z,1747668700.057 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0028.lzma 2025-05-19T15:31:41.059Z,1747668701.059 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0028.lzma.bak 2025-05-19T15:31:41.060Z,1747668701.060 [DataOverHttps](INFO): SBD MOMSN=24920302 2025-05-19T15:31:57.469Z,1747668717.469 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250519T143346/Express0026.lzma 2025-05-19T15:31:58.473Z,1747668718.473 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0026.lzma.bak 2025-05-19T15:31:58.473Z,1747668718.473 [DataOverHttps](INFO): SBD MOMSN=24920305 2025-05-19T15:32:06.482Z,1747668726.482 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:32:14.842Z,1747668734.842 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0029.lzma 2025-05-19T15:32:15.844Z,1747668735.844 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0029.lzma.bak 2025-05-19T15:32:15.844Z,1747668735.844 [DataOverHttps](INFO): SBD MOMSN=24920308 2025-05-19T15:32:16.990Z,1747668736.990 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:32:16.990Z,1747668736.990 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:32:16.990Z,1747668736.990 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:37:17.795Z,1747669037.795 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:37:17.795Z,1747669037.795 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:37:17.795Z,1747669037.795 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:37:17.795Z,1747669037.795 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:37:18.192Z,1747669038.192 [Default:CheckIn:D] Stopped 2025-05-19T15:37:18.192Z,1747669038.192 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:37:18.597Z,1747669038.597 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.254903 min 2025-05-19T15:37:18.597Z,1747669038.597 [Default:CheckIn:E] Stopped 2025-05-19T15:37:18.597Z,1747669038.597 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:37:18.597Z,1747669038.597 [Default:CheckIn] Stopped 2025-05-19T15:37:18.597Z,1747669038.597 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:37:18.598Z,1747669038.598 [Default:CheckIn](INFO): Running loop #9 2025-05-19T15:37:18.598Z,1747669038.598 [Default:CheckIn] Running Loop=9 2025-05-19T15:37:18.598Z,1747669038.598 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:37:18.598Z,1747669038.598 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:37:20.620Z,1747669040.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153719.00,A,3648.13876,N,12147.23010,W,0.019,69.93,190525,,,D*45 2025-05-19T15:37:20.626Z,1747669040.626 [NAL9602](INFO): GPS fix at 20250519T153719: (36.802313, -121.787168) 2025-05-19T15:37:20.678Z,1747669040.678 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:37:20.678Z,1747669040.678 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:37:28.830Z,1747669048.830 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0031.lzma 2025-05-19T15:37:29.831Z,1747669049.831 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0031.lzma.bak 2025-05-19T15:37:29.831Z,1747669049.831 [DataOverHttps](INFO): SBD MOMSN=24920364 2025-05-19T15:37:46.113Z,1747669066.113 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250519T143346/Express0032.lzma 2025-05-19T15:37:47.115Z,1747669067.115 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0032.lzma.bak 2025-05-19T15:37:47.115Z,1747669067.115 [DataOverHttps](INFO): SBD MOMSN=24920367 2025-05-19T15:37:48.494Z,1747669068.494 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:37:48.494Z,1747669068.494 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:37:48.494Z,1747669068.494 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:37:50.508Z,1747669070.508 [NAL9602](INFO): SBD MO Status=2, MOMSN=63134, MT Status=2, MTMSN=0 2025-05-19T15:37:50.508Z,1747669070.508 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T15:38:00.217Z,1747669080.217 [NAL9602](INFO): SBD MO Status=0, MOMSN=63134, MT Status=0, MTMSN=0 2025-05-19T15:38:00.217Z,1747669080.217 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:38:30.954Z,1747669110.954 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:42:49.218Z,1747669369.218 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:42:49.218Z,1747669369.218 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:42:49.218Z,1747669369.218 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:42:49.219Z,1747669369.219 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:42:49.624Z,1747669369.624 [Default:CheckIn:D] Stopped 2025-05-19T15:42:49.624Z,1747669369.624 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:42:50.094Z,1747669370.094 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.778764 min 2025-05-19T15:42:50.094Z,1747669370.094 [Default:CheckIn:E] Stopped 2025-05-19T15:42:50.094Z,1747669370.094 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:42:50.094Z,1747669370.094 [Default:CheckIn] Stopped 2025-05-19T15:42:50.094Z,1747669370.094 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:42:50.094Z,1747669370.094 [Default:CheckIn](INFO): Running loop #10 2025-05-19T15:42:50.095Z,1747669370.095 [Default:CheckIn] Running Loop=10 2025-05-19T15:42:50.095Z,1747669370.095 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:42:50.095Z,1747669370.095 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:42:52.041Z,1747669372.041 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154251.00,A,3648.13831,N,12147.22927,W,0.019,0.00,190525,,,D*71 2025-05-19T15:42:52.043Z,1747669372.043 [NAL9602](INFO): GPS fix at 20250519T154251: (36.802305, -121.787154) 2025-05-19T15:42:52.055Z,1747669372.055 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:42:52.055Z,1747669372.055 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:43:01.077Z,1747669381.077 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0034.lzma 2025-05-19T15:43:02.079Z,1747669382.079 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0034.lzma.bak 2025-05-19T15:43:02.079Z,1747669382.079 [DataOverHttps](INFO): SBD MOMSN=24920400 2025-05-19T15:43:18.353Z,1747669398.353 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250519T143346/Express0035.lzma 2025-05-19T15:43:19.356Z,1747669399.356 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0035.lzma.bak 2025-05-19T15:43:19.356Z,1747669399.356 [DataOverHttps](INFO): SBD MOMSN=24920403 2025-05-19T15:43:20.672Z,1747669400.672 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:43:20.673Z,1747669400.673 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:43:20.673Z,1747669400.673 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:43:25.908Z,1747669405.908 [NAL9602](INFO): SBD MO Status=0, MOMSN=63135, MT Status=0, MTMSN=0 2025-05-19T15:43:25.908Z,1747669405.908 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:43:56.607Z,1747669436.607 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:48:21.285Z,1747669701.285 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:48:21.285Z,1747669701.285 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:48:21.285Z,1747669701.285 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:48:21.285Z,1747669701.285 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:48:21.693Z,1747669701.693 [Default:CheckIn:D] Stopped 2025-05-19T15:48:21.693Z,1747669701.693 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.313249 min 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn:E] Stopped 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn] Stopped 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn](INFO): Running loop #11 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn] Running Loop=11 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:48:22.104Z,1747669702.104 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:48:24.109Z,1747669704.109 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154823.00,A,3648.14042,N,12147.22741,W,0.019,0.00,190525,,,D*7B 2025-05-19T15:48:24.111Z,1747669704.111 [NAL9602](INFO): GPS fix at 20250519T154823: (36.802340, -121.787124) 2025-05-19T15:48:24.124Z,1747669704.124 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:48:24.124Z,1747669704.124 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:48:32.165Z,1747669712.165 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0037.lzma 2025-05-19T15:48:33.167Z,1747669713.167 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0037.lzma.bak 2025-05-19T15:48:33.167Z,1747669713.167 [DataOverHttps](INFO): SBD MOMSN=24920501 2025-05-19T15:48:37.520Z,1747669717.520 [NAL9602](INFO): SBD MO Status=0, MOMSN=63136, MT Status=0, MTMSN=0 2025-05-19T15:48:37.520Z,1747669717.520 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:48:50.805Z,1747669730.805 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0038.lzma 2025-05-19T15:48:51.807Z,1747669731.807 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0038.lzma.bak 2025-05-19T15:48:51.808Z,1747669731.808 [DataOverHttps](INFO): SBD MOMSN=24920504 2025-05-19T15:48:52.904Z,1747669732.904 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:48:52.904Z,1747669732.904 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:48:52.904Z,1747669732.904 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:49:08.264Z,1747669748.264 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:53:53.489Z,1747670033.489 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:53:53.489Z,1747670033.489 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:53:53.489Z,1747670033.489 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:53:53.489Z,1747670033.489 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:53:53.904Z,1747670033.904 [Default:CheckIn:D] Stopped 2025-05-19T15:53:53.904Z,1747670033.904 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:53:54.304Z,1747670034.304 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.850106 min 2025-05-19T15:53:54.304Z,1747670034.304 [Default:CheckIn:E] Stopped 2025-05-19T15:53:54.304Z,1747670034.304 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:53:54.304Z,1747670034.304 [Default:CheckIn] Stopped 2025-05-19T15:53:54.305Z,1747670034.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:53:54.305Z,1747670034.305 [Default:CheckIn](INFO): Running loop #12 2025-05-19T15:53:54.305Z,1747670034.305 [Default:CheckIn] Running Loop=12 2025-05-19T15:53:54.305Z,1747670034.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:53:54.305Z,1747670034.305 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:53:56.309Z,1747670036.309 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155355.00,A,3648.13811,N,12147.22733,W,0.039,0.00,190525,,,D*7E 2025-05-19T15:53:56.311Z,1747670036.311 [NAL9602](INFO): GPS fix at 20250519T155355: (36.802302, -121.787122) 2025-05-19T15:53:56.323Z,1747670036.323 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:53:56.323Z,1747670036.323 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:54:04.365Z,1747670044.365 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0040.lzma 2025-05-19T15:54:05.367Z,1747670045.367 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0040.lzma.bak 2025-05-19T15:54:05.367Z,1747670045.367 [DataOverHttps](INFO): SBD MOMSN=24920518 2025-05-19T15:54:24.736Z,1747670064.736 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250519T143346/Express0041.lzma 2025-05-19T15:54:25.735Z,1747670065.735 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0041.lzma.bak 2025-05-19T15:54:25.735Z,1747670065.735 [DataOverHttps](INFO): SBD MOMSN=24920521 2025-05-19T15:54:26.662Z,1747670066.662 [NAL9602](INFO): SBD MO Status=0, MOMSN=63137, MT Status=0, MTMSN=0 2025-05-19T15:54:26.662Z,1747670066.662 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:54:27.083Z,1747670067.083 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:54:27.083Z,1747670067.083 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:54:27.083Z,1747670067.083 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T15:54:57.378Z,1747670097.378 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T15:59:27.652Z,1747670367.652 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T15:59:27.652Z,1747670367.652 [Default:CheckIn:C.Wait] Stopped 2025-05-19T15:59:27.652Z,1747670367.652 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T15:59:27.652Z,1747670367.652 [Default:CheckIn:D] Running Loop=1 2025-05-19T15:59:28.054Z,1747670368.054 [Default:CheckIn:D] Stopped 2025-05-19T15:59:28.055Z,1747670368.055 [Default:CheckIn:E] Running Loop=1 2025-05-19T15:59:28.495Z,1747670368.495 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.419271 min 2025-05-19T15:59:28.495Z,1747670368.495 [Default:CheckIn:E] Stopped 2025-05-19T15:59:28.496Z,1747670368.496 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T15:59:28.496Z,1747670368.496 [Default:CheckIn] Stopped 2025-05-19T15:59:28.496Z,1747670368.496 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T15:59:28.496Z,1747670368.496 [Default:CheckIn](INFO): Running loop #13 2025-05-19T15:59:28.496Z,1747670368.496 [Default:CheckIn] Running Loop=13 2025-05-19T15:59:28.496Z,1747670368.496 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T15:59:28.496Z,1747670368.496 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T15:59:30.468Z,1747670370.468 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155929.00,A,3648.14074,N,12147.22904,W,0.078,0.00,190525,,,D*7C 2025-05-19T15:59:30.470Z,1747670370.470 [NAL9602](INFO): GPS fix at 20250519T155929: (36.802346, -121.787151) 2025-05-19T15:59:30.481Z,1747670370.481 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T15:59:30.481Z,1747670370.481 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T15:59:38.182Z,1747670378.182 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0043.lzma 2025-05-19T15:59:39.183Z,1747670379.183 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0043.lzma.bak 2025-05-19T15:59:39.183Z,1747670379.183 [DataOverHttps](INFO): SBD MOMSN=24920578 2025-05-19T15:59:44.612Z,1747670384.612 [NAL9602](INFO): SBD MO Status=0, MOMSN=63138, MT Status=0, MTMSN=0 2025-05-19T15:59:44.612Z,1747670384.612 [NAL9602](INFO): No messages in MT queue 2025-05-19T15:59:55.537Z,1747670395.537 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250519T143346/Express0044.lzma 2025-05-19T15:59:56.539Z,1747670396.539 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0044.lzma.bak 2025-05-19T15:59:56.539Z,1747670396.539 [DataOverHttps](INFO): SBD MOMSN=24920581 2025-05-19T15:59:57.568Z,1747670397.568 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T15:59:57.568Z,1747670397.568 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T15:59:57.568Z,1747670397.568 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:00:15.323Z,1747670415.323 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:04:58.178Z,1747670698.178 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:04:58.178Z,1747670698.178 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:04:58.178Z,1747670698.178 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:04:58.178Z,1747670698.178 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:04:58.587Z,1747670698.587 [Default:CheckIn:D] Stopped 2025-05-19T16:04:58.587Z,1747670698.587 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:04:58.988Z,1747670698.988 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.928149 min 2025-05-19T16:04:58.988Z,1747670698.988 [Default:CheckIn:E] Stopped 2025-05-19T16:04:58.989Z,1747670698.989 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:04:58.989Z,1747670698.989 [Default:CheckIn] Stopped 2025-05-19T16:04:58.989Z,1747670698.989 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:04:59.005Z,1747670699.005 [Default:CheckIn](INFO): Running loop #14 2025-05-19T16:04:59.006Z,1747670699.006 [Default:CheckIn] Running Loop=14 2025-05-19T16:04:59.006Z,1747670699.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:04:59.006Z,1747670699.006 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:05:01.000Z,1747670701.000 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160500.00,A,3648.14010,N,12147.23094,W,0.058,0.00,190525,,,D*7C 2025-05-19T16:05:01.002Z,1747670701.002 [NAL9602](INFO): GPS fix at 20250519T160500: (36.802335, -121.787182) 2025-05-19T16:05:01.014Z,1747670701.014 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:05:01.014Z,1747670701.014 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:05:08.485Z,1747670708.485 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250519T143346/Courier0046.lzma 2025-05-19T16:05:09.487Z,1747670709.487 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0046.lzma.bak 2025-05-19T16:05:09.487Z,1747670709.487 [DataOverHttps](INFO): SBD MOMSN=24920597 2025-05-19T16:05:25.841Z,1747670725.841 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0047.lzma 2025-05-19T16:05:26.843Z,1747670726.843 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0047.lzma.bak 2025-05-19T16:05:26.844Z,1747670726.844 [DataOverHttps](INFO): SBD MOMSN=24920600 2025-05-19T16:05:28.159Z,1747670728.159 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:05:28.159Z,1747670728.159 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:05:28.159Z,1747670728.159 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:05:45.518Z,1747670745.518 [NAL9602](INFO): SBD MO Status=0, MOMSN=63139, MT Status=0, MTMSN=0 2025-05-19T16:05:45.518Z,1747670745.518 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:06:05.712Z,1747670765.712 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:06:16.219Z,1747670776.219 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:06:17.833Z,1747670777.833 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:06:29.953Z,1747670789.953 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:06:41.670Z,1747670801.670 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:06:53.385Z,1747670813.385 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:07:05.504Z,1747670825.504 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:07:16.824Z,1747670836.824 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:07:28.539Z,1747670848.539 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:10:03.677Z,1747671003.677 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:10:17.013Z,1747671017.013 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:10:28.752Z,1747671028.752 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:10:28.752Z,1747671028.752 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:10:28.752Z,1747671028.752 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:10:28.752Z,1747671028.752 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:10:29.152Z,1747671029.152 [Default:CheckIn:D] Stopped 2025-05-19T16:10:29.152Z,1747671029.152 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:10:29.550Z,1747671029.550 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.437557 min 2025-05-19T16:10:29.550Z,1747671029.550 [Default:CheckIn:E] Stopped 2025-05-19T16:10:29.550Z,1747671029.550 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:10:29.550Z,1747671029.550 [Default:CheckIn] Stopped 2025-05-19T16:10:29.550Z,1747671029.550 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:10:29.550Z,1747671029.550 [Default:CheckIn](INFO): Running loop #15 2025-05-19T16:10:29.551Z,1747671029.551 [Default:CheckIn] Running Loop=15 2025-05-19T16:10:29.551Z,1747671029.551 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:10:29.551Z,1747671029.551 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:10:30.749Z,1747671030.749 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:10:31.580Z,1747671031.580 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161030.00,A,3648.14800,N,12147.22739,W,0.058,26.69,190525,,,D*48 2025-05-19T16:10:31.583Z,1747671031.583 [NAL9602](INFO): GPS fix at 20250519T161030: (36.802467, -121.787123) 2025-05-19T16:10:31.598Z,1747671031.598 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:10:31.598Z,1747671031.598 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:10:39.397Z,1747671039.397 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0049.lzma 2025-05-19T16:10:40.399Z,1747671040.399 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0049.lzma.bak 2025-05-19T16:10:40.399Z,1747671040.399 [DataOverHttps](INFO): SBD MOMSN=24920665 2025-05-19T16:10:44.082Z,1747671044.082 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:10:48.529Z,1747671048.529 [NAL9602](INFO): SBD MO Status=0, MOMSN=63140, MT Status=0, MTMSN=0 2025-05-19T16:10:48.529Z,1747671048.529 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:10:57.459Z,1747671057.459 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:10:59.645Z,1747671059.645 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0050.lzma 2025-05-19T16:11:00.647Z,1747671060.647 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0050.lzma.bak 2025-05-19T16:11:00.647Z,1747671060.647 [DataOverHttps](INFO): SBD MOMSN=24920668 2025-05-19T16:11:01.916Z,1747671061.916 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:11:01.916Z,1747671061.916 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:11:01.917Z,1747671061.917 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:11:10.789Z,1747671070.789 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:11:19.294Z,1747671079.294 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:11:24.122Z,1747671084.122 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:11:37.453Z,1747671097.453 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:11:51.190Z,1747671111.190 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:12:05.333Z,1747671125.333 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:12:18.661Z,1747671138.661 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:14:04.918Z,1747671244.918 [Sonardyne_Nano](INFO): Battery at maximum, disabling charging 2025-05-19T16:14:22.291Z,1747671262.291 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-05-19T16:16:02.500Z,1747671362.500 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:16:02.500Z,1747671362.500 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:16:02.500Z,1747671362.500 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:16:02.500Z,1747671362.500 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:16:02.958Z,1747671362.958 [Default:CheckIn:D] Stopped 2025-05-19T16:16:02.958Z,1747671362.958 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:16:03.305Z,1747671363.305 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.001001 min 2025-05-19T16:16:03.305Z,1747671363.305 [Default:CheckIn:E] Stopped 2025-05-19T16:16:03.306Z,1747671363.306 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:16:03.306Z,1747671363.306 [Default:CheckIn] Stopped 2025-05-19T16:16:03.306Z,1747671363.306 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:16:03.306Z,1747671363.306 [Default:CheckIn](INFO): Running loop #16 2025-05-19T16:16:03.306Z,1747671363.306 [Default:CheckIn] Running Loop=16 2025-05-19T16:16:03.306Z,1747671363.306 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:16:03.306Z,1747671363.306 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:16:05.313Z,1747671365.313 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161604.00,A,3648.14911,N,12147.22696,W,0.039,26.69,190525,,,D*4B 2025-05-19T16:16:05.315Z,1747671365.315 [NAL9602](INFO): GPS fix at 20250519T161604: (36.802485, -121.787116) 2025-05-19T16:16:05.326Z,1747671365.326 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:16:05.326Z,1747671365.326 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:16:13.069Z,1747671373.069 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0052.lzma 2025-05-19T16:16:14.071Z,1747671374.071 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0052.lzma.bak 2025-05-19T16:16:14.071Z,1747671374.071 [DataOverHttps](INFO): SBD MOMSN=24920724 2025-05-19T16:16:27.172Z,1747671387.172 [NAL9602](INFO): SBD MO Status=0, MOMSN=63141, MT Status=0, MTMSN=0 2025-05-19T16:16:27.172Z,1747671387.172 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:16:33.290Z,1747671393.290 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20250519T143346/Express0053.lzma 2025-05-19T16:16:34.287Z,1747671394.287 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0053.lzma.bak 2025-05-19T16:16:34.287Z,1747671394.287 [DataOverHttps](INFO): SBD MOMSN=24920727 2025-05-19T16:16:35.680Z,1747671395.680 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:16:35.680Z,1747671395.680 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:16:35.680Z,1747671395.680 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:16:57.891Z,1747671417.891 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:19:45.537Z,1747671585.537 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:20:00.888Z,1747671600.888 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:20:16.242Z,1747671616.242 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:20:32.004Z,1747671632.004 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:20:47.755Z,1747671647.755 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:21:03.508Z,1747671663.508 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:21:19.266Z,1747671679.266 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:21:35.427Z,1747671695.427 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:21:36.268Z,1747671696.268 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:21:36.268Z,1747671696.268 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:21:36.268Z,1747671696.268 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:21:36.269Z,1747671696.269 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:21:36.658Z,1747671696.658 [Default:CheckIn:D] Stopped 2025-05-19T16:21:36.658Z,1747671696.658 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:21:37.056Z,1747671697.056 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.562663 min 2025-05-19T16:21:37.056Z,1747671697.056 [Default:CheckIn:E] Stopped 2025-05-19T16:21:37.056Z,1747671697.056 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:21:37.056Z,1747671697.056 [Default:CheckIn] Stopped 2025-05-19T16:21:37.057Z,1747671697.057 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:21:37.057Z,1747671697.057 [Default:CheckIn](INFO): Running loop #17 2025-05-19T16:21:37.057Z,1747671697.057 [Default:CheckIn] Running Loop=17 2025-05-19T16:21:37.057Z,1747671697.057 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:21:37.057Z,1747671697.057 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:21:39.084Z,1747671699.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162138.00,A,3648.15368,N,12147.22168,W,0.097,37.97,190525,,,A*43 2025-05-19T16:21:39.087Z,1747671699.087 [NAL9602](INFO): GPS fix at 20250519T162138: (36.802561, -121.787028) 2025-05-19T16:21:39.098Z,1747671699.098 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:21:39.098Z,1747671699.098 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:21:46.493Z,1747671706.493 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0055.lzma 2025-05-19T16:21:47.495Z,1747671707.495 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0055.lzma.bak 2025-05-19T16:21:47.495Z,1747671707.495 [DataOverHttps](INFO): SBD MOMSN=24920794 2025-05-19T16:21:51.289Z,1747671711.289 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:21:53.608Z,1747671713.608 [NAL9602](INFO): SBD MO Status=0, MOMSN=63142, MT Status=0, MTMSN=0 2025-05-19T16:21:53.608Z,1747671713.608 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:22:03.617Z,1747671723.617 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250519T143346/Express0056.lzma 2025-05-19T16:22:04.619Z,1747671724.619 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0056.lzma.bak 2025-05-19T16:22:04.619Z,1747671724.619 [DataOverHttps](INFO): SBD MOMSN=24920797 2025-05-19T16:22:05.784Z,1747671725.784 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:22:05.784Z,1747671725.784 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:22:05.784Z,1747671725.784 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:22:24.326Z,1747671744.326 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:27:06.341Z,1747672026.341 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:27:06.345Z,1747672026.345 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:27:06.345Z,1747672026.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:27:06.345Z,1747672026.345 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:27:06.744Z,1747672026.744 [Default:CheckIn:D] Stopped 2025-05-19T16:27:06.744Z,1747672026.744 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:27:07.127Z,1747672027.127 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.064103 min 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn:E] Stopped 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn] Stopped 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn](INFO): Running loop #18 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn] Running Loop=18 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:27:07.128Z,1747672027.128 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:27:09.140Z,1747672029.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162708.00,A,3648.16147,N,12147.21404,W,0.661,33.75,190525,,,A*41 2025-05-19T16:27:09.142Z,1747672029.142 [NAL9602](INFO): GPS fix at 20250519T162708: (36.802691, -121.786901) 2025-05-19T16:27:09.153Z,1747672029.153 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:27:09.153Z,1747672029.153 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:27:16.941Z,1747672036.941 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0058.lzma 2025-05-19T16:27:17.943Z,1747672037.943 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0058.lzma.bak 2025-05-19T16:27:17.943Z,1747672037.943 [DataOverHttps](INFO): SBD MOMSN=24920812 2025-05-19T16:27:22.068Z,1747672042.068 [NAL9602](INFO): SBD MO Status=0, MOMSN=63143, MT Status=0, MTMSN=0 2025-05-19T16:27:22.068Z,1747672042.068 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:27:33.913Z,1747672053.913 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250519T143346/Express0059.lzma 2025-05-19T16:27:34.915Z,1747672054.915 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0059.lzma.bak 2025-05-19T16:27:34.915Z,1747672054.915 [DataOverHttps](INFO): SBD MOMSN=24920815 2025-05-19T16:27:36.220Z,1747672056.220 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:27:36.220Z,1747672056.220 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:27:36.220Z,1747672056.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:27:52.788Z,1747672072.788 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:29:27.371Z,1747672167.371 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:29:40.639Z,1747672180.639 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:29:53.969Z,1747672193.969 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:30:07.306Z,1747672207.306 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:30:20.636Z,1747672220.636 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:30:33.965Z,1747672233.965 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:30:47.701Z,1747672247.701 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:31:01.033Z,1747672261.033 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:31:13.961Z,1747672273.961 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:31:15.728Z,1747672275.728 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-05-19T16:31:27.697Z,1747672287.697 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:31:41.030Z,1747672301.030 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T16:32:36.851Z,1747672356.851 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:32:36.851Z,1747672356.851 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:32:36.852Z,1747672356.852 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:32:36.852Z,1747672356.852 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:32:37.218Z,1747672357.218 [Default:CheckIn:D] Stopped 2025-05-19T16:32:37.218Z,1747672357.218 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:32:37.630Z,1747672357.630 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.571989 min 2025-05-19T16:32:37.630Z,1747672357.630 [Default:CheckIn:E] Stopped 2025-05-19T16:32:37.630Z,1747672357.630 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:32:37.630Z,1747672357.630 [Default:CheckIn] Stopped 2025-05-19T16:32:37.630Z,1747672357.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:32:37.630Z,1747672357.630 [Default:CheckIn](INFO): Running loop #19 2025-05-19T16:32:37.631Z,1747672357.631 [Default:CheckIn] Running Loop=19 2025-05-19T16:32:37.631Z,1747672357.631 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:32:37.631Z,1747672357.631 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:32:39.620Z,1747672359.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163238.00,A,3648.16483,N,12147.21425,W,0.039,22.22,190525,,,A*41 2025-05-19T16:32:39.623Z,1747672359.623 [NAL9602](INFO): GPS fix at 20250519T163238: (36.802747, -121.786904) 2025-05-19T16:32:39.634Z,1747672359.634 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:32:39.634Z,1747672359.634 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:32:47.693Z,1747672367.693 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0061.lzma 2025-05-19T16:32:48.695Z,1747672368.695 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0061.lzma.bak 2025-05-19T16:32:48.695Z,1747672368.695 [DataOverHttps](INFO): SBD MOMSN=24920878 2025-05-19T16:33:07.625Z,1747672387.625 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250519T143346/Express0062.lzma 2025-05-19T16:33:08.627Z,1747672388.627 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0062.lzma.bak 2025-05-19T16:33:08.627Z,1747672388.627 [DataOverHttps](INFO): SBD MOMSN=24920881 2025-05-19T16:33:09.981Z,1747672389.981 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:33:09.981Z,1747672389.981 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:33:09.981Z,1747672389.981 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:33:45.124Z,1747672425.124 [NAL9602](INFO): SBD MO Status=0, MOMSN=63144, MT Status=0, MTMSN=0 2025-05-19T16:33:45.124Z,1747672425.124 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:34:15.822Z,1747672455.822 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:36:00.884Z,1747672560.884 [BPC1](ERROR): Battery stick #31 (s/n: 029D) reported TERMINATE_CHARGE_ALARM. Status code: 0x40C0. 2025-05-19T16:36:00.886Z,1747672560.886 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2025-05-19T16:36:00.888Z,1747672560.888 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2025-05-19T16:38:10.652Z,1747672690.652 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:38:10.652Z,1747672690.652 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:38:10.652Z,1747672690.652 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:38:10.652Z,1747672690.652 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:38:11.038Z,1747672691.038 [Default:CheckIn:D] Stopped 2025-05-19T16:38:11.038Z,1747672691.038 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:38:11.443Z,1747672691.443 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.135669 min 2025-05-19T16:38:11.443Z,1747672691.443 [Default:CheckIn:E] Stopped 2025-05-19T16:38:11.444Z,1747672691.444 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:38:11.444Z,1747672691.444 [Default:CheckIn] Stopped 2025-05-19T16:38:11.444Z,1747672691.444 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:38:11.444Z,1747672691.444 [Default:CheckIn](INFO): Running loop #20 2025-05-19T16:38:11.444Z,1747672691.444 [Default:CheckIn] Running Loop=20 2025-05-19T16:38:11.444Z,1747672691.444 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:38:11.444Z,1747672691.444 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:38:13.448Z,1747672693.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163812.00,A,3648.16337,N,12147.21228,W,0.039,22.22,190525,,,A*40 2025-05-19T16:38:13.459Z,1747672693.459 [NAL9602](INFO): GPS fix at 20250519T163812: (36.802723, -121.786871) 2025-05-19T16:38:13.471Z,1747672693.471 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:38:13.471Z,1747672693.471 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:38:24.020Z,1747672704.020 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250519T143346/Courier0064.lzma 2025-05-19T16:38:25.023Z,1747672705.023 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0064.lzma.bak 2025-05-19T16:38:25.023Z,1747672705.023 [DataOverHttps](INFO): SBD MOMSN=24920904 2025-05-19T16:38:41.657Z,1747672721.657 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250519T143346/Express0065.lzma 2025-05-19T16:38:42.659Z,1747672722.659 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0065.lzma.bak 2025-05-19T16:38:42.659Z,1747672722.659 [DataOverHttps](INFO): SBD MOMSN=24920950 2025-05-19T16:38:43.818Z,1747672723.818 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:38:43.818Z,1747672723.818 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:38:43.818Z,1747672723.818 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:38:45.816Z,1747672725.816 [NAL9602](INFO): SBD MO Status=0, MOMSN=63145, MT Status=0, MTMSN=0 2025-05-19T16:38:45.816Z,1747672725.816 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:39:16.562Z,1747672756.562 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:43:44.248Z,1747673024.248 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:43:44.248Z,1747673024.248 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:43:44.248Z,1747673024.248 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:43:44.248Z,1747673024.248 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:43:44.654Z,1747673024.654 [Default:CheckIn:D] Stopped 2025-05-19T16:43:44.654Z,1747673024.654 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.695923 min 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn:E] Stopped 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn] Stopped 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn](INFO): Running loop #21 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn] Running Loop=21 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:43:45.055Z,1747673025.055 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:43:47.064Z,1747673027.064 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164346.00,A,3648.16415,N,12147.21236,W,0.039,22.22,190525,,,A*45 2025-05-19T16:43:47.078Z,1747673027.078 [NAL9602](INFO): GPS fix at 20250519T164346: (36.802736, -121.786873) 2025-05-19T16:43:47.095Z,1747673027.095 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:43:47.096Z,1747673027.096 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:43:54.897Z,1747673034.897 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0067.lzma 2025-05-19T16:43:55.931Z,1747673035.931 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0067.lzma.bak 2025-05-19T16:43:55.931Z,1747673035.931 [DataOverHttps](INFO): SBD MOMSN=24920965 2025-05-19T16:44:05.652Z,1747673045.652 [NAL9602](INFO): SBD MO Status=0, MOMSN=63146, MT Status=0, MTMSN=0 2025-05-19T16:44:05.652Z,1747673045.652 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:44:11.969Z,1747673051.969 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250519T143346/Express0068.lzma 2025-05-19T16:44:12.971Z,1747673052.971 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0068.lzma.bak 2025-05-19T16:44:12.971Z,1747673052.971 [DataOverHttps](INFO): SBD MOMSN=24920968 2025-05-19T16:44:14.140Z,1747673054.140 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:44:14.141Z,1747673054.141 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:44:14.141Z,1747673054.141 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:44:36.386Z,1747673076.386 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:49:14.638Z,1747673354.638 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:49:14.638Z,1747673354.638 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:49:14.639Z,1747673354.639 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:49:14.639Z,1747673354.639 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:49:15.026Z,1747673355.026 [Default:CheckIn:D] Stopped 2025-05-19T16:49:15.026Z,1747673355.026 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:49:15.427Z,1747673355.427 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.202124 min 2025-05-19T16:49:15.427Z,1747673355.427 [Default:CheckIn:E] Stopped 2025-05-19T16:49:15.427Z,1747673355.427 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:49:15.427Z,1747673355.427 [Default:CheckIn] Stopped 2025-05-19T16:49:15.427Z,1747673355.427 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:49:15.427Z,1747673355.427 [Default:CheckIn](INFO): Running loop #22 2025-05-19T16:49:15.428Z,1747673355.428 [Default:CheckIn] Running Loop=22 2025-05-19T16:49:15.428Z,1747673355.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:49:15.428Z,1747673355.428 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:49:17.445Z,1747673357.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164916.00,A,3648.16475,N,12147.21225,W,0.039,22.22,190525,,,A*4E 2025-05-19T16:49:17.447Z,1747673357.447 [NAL9602](INFO): GPS fix at 20250519T164916: (36.802746, -121.786871) 2025-05-19T16:49:17.459Z,1747673357.459 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:49:17.459Z,1747673357.459 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:49:25.225Z,1747673365.225 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0070.lzma 2025-05-19T16:49:26.227Z,1747673366.227 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0070.lzma.bak 2025-05-19T16:49:26.227Z,1747673366.227 [DataOverHttps](INFO): SBD MOMSN=24921033 2025-05-19T16:49:42.229Z,1747673382.229 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250519T143346/Express0071.lzma 2025-05-19T16:49:43.231Z,1747673383.231 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0071.lzma.bak 2025-05-19T16:49:43.231Z,1747673383.231 [DataOverHttps](INFO): SBD MOMSN=24921036 2025-05-19T16:49:43.302Z,1747673383.302 [NAL9602](INFO): SBD MO Status=0, MOMSN=63147, MT Status=0, MTMSN=0 2025-05-19T16:49:43.302Z,1747673383.302 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:49:44.520Z,1747673384.520 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:49:44.520Z,1747673384.520 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:49:44.520Z,1747673384.520 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:50:13.994Z,1747673413.994 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T16:54:45.316Z,1747673685.316 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T16:54:45.316Z,1747673685.316 [Default:CheckIn:C.Wait] Stopped 2025-05-19T16:54:45.316Z,1747673685.316 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T16:54:45.316Z,1747673685.316 [Default:CheckIn:D] Running Loop=1 2025-05-19T16:54:45.731Z,1747673685.731 [Default:CheckIn:D] Stopped 2025-05-19T16:54:45.731Z,1747673685.731 [Default:CheckIn:E] Running Loop=1 2025-05-19T16:54:46.126Z,1747673686.126 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.713867 min 2025-05-19T16:54:46.126Z,1747673686.126 [Default:CheckIn:E] Stopped 2025-05-19T16:54:46.126Z,1747673686.126 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T16:54:46.126Z,1747673686.126 [Default:CheckIn] Stopped 2025-05-19T16:54:46.126Z,1747673686.126 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T16:54:46.126Z,1747673686.126 [Default:CheckIn](INFO): Running loop #23 2025-05-19T16:54:46.126Z,1747673686.126 [Default:CheckIn] Running Loop=23 2025-05-19T16:54:46.127Z,1747673686.127 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T16:54:46.127Z,1747673686.127 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T16:54:48.140Z,1747673688.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165447.00,A,3648.16418,N,12147.21273,W,0.019,22.22,190525,,,A*4C 2025-05-19T16:54:48.151Z,1747673688.151 [NAL9602](INFO): GPS fix at 20250519T165447: (36.802736, -121.786879) 2025-05-19T16:54:48.161Z,1747673688.161 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T16:54:48.161Z,1747673688.161 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T16:54:58.457Z,1747673698.457 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0073.lzma 2025-05-19T16:54:59.459Z,1747673699.459 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0073.lzma.bak 2025-05-19T16:54:59.459Z,1747673699.459 [DataOverHttps](INFO): SBD MOMSN=24921051 2025-05-19T16:55:01.528Z,1747673701.528 [NAL9602](INFO): SBD MO Status=0, MOMSN=63148, MT Status=0, MTMSN=0 2025-05-19T16:55:01.528Z,1747673701.528 [NAL9602](INFO): No messages in MT queue 2025-05-19T16:55:15.293Z,1747673715.293 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0074.lzma 2025-05-19T16:55:16.295Z,1747673716.295 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0074.lzma.bak 2025-05-19T16:55:16.295Z,1747673716.295 [DataOverHttps](INFO): SBD MOMSN=24921054 2025-05-19T16:55:17.696Z,1747673717.696 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T16:55:17.696Z,1747673717.696 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T16:55:17.696Z,1747673717.696 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T16:55:32.234Z,1747673732.234 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:00:18.110Z,1747674018.110 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:00:18.110Z,1747674018.110 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:00:18.110Z,1747674018.110 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:00:18.110Z,1747674018.110 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:00:18.498Z,1747674018.498 [Default:CheckIn:D] Stopped 2025-05-19T17:00:18.498Z,1747674018.498 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:00:18.902Z,1747674018.902 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.259993 min 2025-05-19T17:00:18.902Z,1747674018.902 [Default:CheckIn:E] Stopped 2025-05-19T17:00:18.903Z,1747674018.903 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:00:18.903Z,1747674018.903 [Default:CheckIn] Stopped 2025-05-19T17:00:18.903Z,1747674018.903 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:00:18.903Z,1747674018.903 [Default:CheckIn](INFO): Running loop #24 2025-05-19T17:00:18.903Z,1747674018.903 [Default:CheckIn] Running Loop=24 2025-05-19T17:00:18.903Z,1747674018.903 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:00:18.903Z,1747674018.903 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:00:20.900Z,1747674020.900 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170020.00,A,3648.16364,N,12147.21166,W,0.058,22.22,190525,,,A*43 2025-05-19T17:00:20.903Z,1747674020.903 [NAL9602](INFO): GPS fix at 20250519T170020: (36.802727, -121.786861) 2025-05-19T17:00:20.945Z,1747674020.945 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:00:20.945Z,1747674020.945 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:00:30.147Z,1747674030.147 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0076.lzma 2025-05-19T17:00:31.143Z,1747674031.143 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0076.lzma.bak 2025-05-19T17:00:31.143Z,1747674031.143 [DataOverHttps](INFO): SBD MOMSN=24921118 2025-05-19T17:00:43.940Z,1747674043.940 [NAL9602](INFO): SBD MO Status=0, MOMSN=63149, MT Status=0, MTMSN=0 2025-05-19T17:00:43.940Z,1747674043.940 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:00:47.501Z,1747674047.501 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0077.lzma 2025-05-19T17:00:48.503Z,1747674048.503 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0077.lzma.bak 2025-05-19T17:00:48.503Z,1747674048.503 [DataOverHttps](INFO): SBD MOMSN=24921121 2025-05-19T17:00:49.616Z,1747674049.616 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:00:49.616Z,1747674049.616 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:00:49.616Z,1747674049.616 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:01:14.702Z,1747674074.702 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:05:50.268Z,1747674350.268 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:05:50.268Z,1747674350.268 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:05:50.268Z,1747674350.268 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:05:50.268Z,1747674350.268 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:05:50.660Z,1747674350.660 [Default:CheckIn:D] Stopped 2025-05-19T17:05:50.660Z,1747674350.660 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:05:51.072Z,1747674351.072 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.796029 min 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn:E] Stopped 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn] Stopped 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn](INFO): Running loop #25 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn] Running Loop=25 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:05:51.073Z,1747674351.073 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:05:53.076Z,1747674353.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170552.00,A,3648.16482,N,12147.21323,W,0.039,22.22,190525,,,A*48 2025-05-19T17:05:53.086Z,1747674353.086 [NAL9602](INFO): GPS fix at 20250519T170552: (36.802747, -121.786887) 2025-05-19T17:05:53.109Z,1747674353.109 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:05:53.110Z,1747674353.110 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:06:00.865Z,1747674360.865 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0079.lzma 2025-05-19T17:06:01.867Z,1747674361.867 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0079.lzma.bak 2025-05-19T17:06:01.867Z,1747674361.867 [DataOverHttps](INFO): SBD MOMSN=24921136 2025-05-19T17:06:08.024Z,1747674368.024 [NAL9602](INFO): SBD MO Status=0, MOMSN=63150, MT Status=0, MTMSN=0 2025-05-19T17:06:08.024Z,1747674368.024 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:06:17.805Z,1747674377.805 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0080.lzma 2025-05-19T17:06:18.807Z,1747674378.807 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0080.lzma.bak 2025-05-19T17:06:18.807Z,1747674378.807 [DataOverHttps](INFO): SBD MOMSN=24921139 2025-05-19T17:06:20.172Z,1747674380.172 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:06:20.172Z,1747674380.172 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:06:20.172Z,1747674380.172 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:06:38.768Z,1747674398.768 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:11:20.826Z,1747674680.826 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:11:20.826Z,1747674680.826 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:11:20.826Z,1747674680.826 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:11:20.827Z,1747674680.827 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:11:21.225Z,1747674681.225 [Default:CheckIn:D] Stopped 2025-05-19T17:11:21.225Z,1747674681.225 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:11:21.631Z,1747674681.631 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.305452 min 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn:E] Stopped 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn] Stopped 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn](INFO): Running loop #26 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn] Running Loop=26 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:11:21.632Z,1747674681.632 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:11:23.640Z,1747674683.640 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171122.00,A,3648.16448,N,12147.21345,W,0.097,0.00,190525,,,A*78 2025-05-19T17:11:23.642Z,1747674683.642 [NAL9602](INFO): GPS fix at 20250519T171122: (36.802741, -121.786891) 2025-05-19T17:11:23.670Z,1747674683.670 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:11:23.670Z,1747674683.670 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:11:31.521Z,1747674691.521 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0082.lzma 2025-05-19T17:11:32.523Z,1747674692.523 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0082.lzma.bak 2025-05-19T17:11:32.523Z,1747674692.523 [DataOverHttps](INFO): SBD MOMSN=24921202 2025-05-19T17:11:38.592Z,1747674698.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=63151, MT Status=0, MTMSN=0 2025-05-19T17:11:38.592Z,1747674698.592 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:11:48.461Z,1747674708.461 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0083.lzma 2025-05-19T17:11:49.463Z,1747674709.463 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0083.lzma.bak 2025-05-19T17:11:49.463Z,1747674709.463 [DataOverHttps](INFO): SBD MOMSN=24921205 2025-05-19T17:11:50.720Z,1747674710.720 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:11:50.720Z,1747674710.720 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:11:50.720Z,1747674710.720 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:12:09.299Z,1747674729.299 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:16:51.353Z,1747675011.353 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:16:51.353Z,1747675011.353 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:16:51.353Z,1747675011.353 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:16:51.353Z,1747675011.353 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:16:51.760Z,1747675011.760 [Default:CheckIn:D] Stopped 2025-05-19T17:16:51.761Z,1747675011.761 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:16:52.182Z,1747675012.182 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.814372 min 2025-05-19T17:16:52.182Z,1747675012.182 [Default:CheckIn:E] Stopped 2025-05-19T17:16:52.183Z,1747675012.183 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:16:52.183Z,1747675012.183 [Default:CheckIn] Stopped 2025-05-19T17:16:52.183Z,1747675012.183 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:16:52.183Z,1747675012.183 [Default:CheckIn](INFO): Running loop #27 2025-05-19T17:16:52.183Z,1747675012.183 [Default:CheckIn] Running Loop=27 2025-05-19T17:16:52.183Z,1747675012.183 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:16:52.183Z,1747675012.183 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:16:54.166Z,1747675014.166 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171653.00,A,3648.16420,N,12147.21179,W,0.019,0.00,190525,,,A*7C 2025-05-19T17:16:54.168Z,1747675014.168 [NAL9602](INFO): GPS fix at 20250519T171653: (36.802737, -121.786863) 2025-05-19T17:16:54.189Z,1747675014.189 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:16:54.189Z,1747675014.189 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:17:02.057Z,1747675022.057 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0085.lzma 2025-05-19T17:17:03.059Z,1747675023.059 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0085.lzma.bak 2025-05-19T17:17:03.059Z,1747675023.059 [DataOverHttps](INFO): SBD MOMSN=24921220 2025-05-19T17:17:19.166Z,1747675039.166 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250519T143346/Express0086.lzma 2025-05-19T17:17:20.167Z,1747675040.167 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0086.lzma.bak 2025-05-19T17:17:20.167Z,1747675040.167 [DataOverHttps](INFO): SBD MOMSN=24921223 2025-05-19T17:17:21.315Z,1747675041.315 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:17:21.315Z,1747675041.315 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:17:21.315Z,1747675041.315 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:17:30.593Z,1747675050.593 [NAL9602](INFO): SBD MO Status=2, MOMSN=63152, MT Status=2, MTMSN=0 2025-05-19T17:17:30.593Z,1747675050.593 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T17:17:44.320Z,1747675064.320 [NAL9602](INFO): SBD MO Status=2, MOMSN=63152, MT Status=2, MTMSN=0 2025-05-19T17:17:44.321Z,1747675064.321 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T17:17:56.444Z,1747675076.444 [NAL9602](INFO): SBD MO Status=0, MOMSN=63152, MT Status=0, MTMSN=0 2025-05-19T17:17:56.444Z,1747675076.444 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:18:27.142Z,1747675107.142 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:22:21.890Z,1747675341.890 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:22:21.890Z,1747675341.890 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:22:21.890Z,1747675341.890 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:22:21.890Z,1747675341.890 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:22:22.295Z,1747675342.295 [Default:CheckIn:D] Stopped 2025-05-19T17:22:22.295Z,1747675342.295 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:22:22.702Z,1747675342.702 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.323275 min 2025-05-19T17:22:22.702Z,1747675342.702 [Default:CheckIn:E] Stopped 2025-05-19T17:22:22.702Z,1747675342.702 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:22:22.702Z,1747675342.702 [Default:CheckIn] Stopped 2025-05-19T17:22:22.702Z,1747675342.702 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:22:22.702Z,1747675342.702 [Default:CheckIn](INFO): Running loop #28 2025-05-19T17:22:22.702Z,1747675342.702 [Default:CheckIn] Running Loop=28 2025-05-19T17:22:22.703Z,1747675342.703 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:22:22.703Z,1747675342.703 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:22:24.704Z,1747675344.704 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172224.00,A,3648.16444,N,12147.21327,W,0.019,0.00,190525,,,A*70 2025-05-19T17:22:24.706Z,1747675344.706 [NAL9602](INFO): GPS fix at 20250519T172224: (36.802741, -121.786888) 2025-05-19T17:22:24.750Z,1747675344.750 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:22:24.750Z,1747675344.750 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:22:32.105Z,1747675352.105 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0088.lzma 2025-05-19T17:22:33.107Z,1747675353.107 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0088.lzma.bak 2025-05-19T17:22:33.107Z,1747675353.107 [DataOverHttps](INFO): SBD MOMSN=24921295 2025-05-19T17:22:39.652Z,1747675359.652 [NAL9602](INFO): SBD MO Status=0, MOMSN=63153, MT Status=0, MTMSN=0 2025-05-19T17:22:39.652Z,1747675359.652 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:22:50.637Z,1747675370.637 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250519T143346/Express0089.lzma 2025-05-19T17:22:51.639Z,1747675371.639 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0089.lzma.bak 2025-05-19T17:22:51.639Z,1747675371.639 [DataOverHttps](INFO): SBD MOMSN=24921298 2025-05-19T17:22:53.010Z,1747675373.010 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:22:53.010Z,1747675373.010 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:22:53.010Z,1747675373.010 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:23:10.371Z,1747675390.371 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:27:04.851Z,1747675624.851 [DataOverHttps](IMPORTANT): SBD MTMSN=20250519T172703 2025-05-19T17:27:12.369Z,1747675632.369 [DataOverHttps](INFO): Received command: ibit 2025-05-19T17:27:12.458Z,1747675632.458 [CommandExec](IMPORTANT): got command ibit 2025-05-19T17:27:12.811Z,1747675632.811 [IBIT](IMPORTANT): Beginning Initiated BIT 2025-05-19T17:27:12.811Z,1747675632.811 [IBIT](IMPORTANT): Beginning control surface checks. 2025-05-19T17:27:12.831Z,1747675632.831 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-05-19T17:27:14.408Z,1747675634.408 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172713.00,A,3648.16403,N,12147.21232,W,0.019,0.00,190525,,,A*77 2025-05-19T17:27:14.410Z,1747675634.410 [NAL9602](INFO): GPS fix at 20250519T172713: (36.802734, -121.786872) 2025-05-19T17:27:17.429Z,1747675637.429 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.000750 CHAN A1 (24V): 0.000513 CHAN A2 (12V): -0.002020 CHAN A3 (5V): -0.001587 CHAN B0 (3.3V): -0.000131 CHAN B1 (3.15aV): 0.000084 CHAN B2 (3.15bV): -0.000204 CHAN B3 (GND): 0.000515 OPEN: -0.000256 Full Scale: +/- 1 mA 2025-05-19T17:27:34.614Z,1747675654.614 [NAL9602](INFO): SBD MO Status=2, MOMSN=63154, MT Status=2, MTMSN=0 2025-05-19T17:27:34.614Z,1747675654.614 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T17:27:52.802Z,1747675672.802 [NAL9602](INFO): SBD MO Status=2, MOMSN=63154, MT Status=2, MTMSN=0 2025-05-19T17:27:52.802Z,1747675672.802 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T17:27:58.871Z,1747675678.871 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802734 Longitude: -121.786873 2025-05-19T17:27:59.278Z,1747675679.278 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.650999 2025-05-19T17:27:59.278Z,1747675679.278 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2025-05-19T17:27:59.278Z,1747675679.278 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2025-05-19T17:27:59.671Z,1747675679.671 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2025-05-19T17:27:59.671Z,1747675679.671 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2025-05-19T17:27:59.671Z,1747675679.671 [IBIT](IMPORTANT): Pressure:9.583372 PSI 2025-05-19T17:27:59.672Z,1747675679.672 [IBIT](IMPORTANT): Humidity:15.364425 % 2025-05-19T17:28:00.078Z,1747675680.078 [IBIT](IMPORTANT): Vehicle Pitch:1.023778 degrees 2025-05-19T17:28:00.078Z,1747675680.078 [IBIT](IMPORTANT): Vehicle Roll:7.215343 degrees 2025-05-19T17:28:00.079Z,1747675680.079 [IBIT](IMPORTANT): Vehicle Heading:8.982600 degrees 2025-05-19T17:28:00.486Z,1747675680.486 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2025-05-19T17:28:00.486Z,1747675680.486 [IBIT](IMPORTANT): buoyancyNeutral: 309.007690 cc 2025-05-19T17:28:00.487Z,1747675680.487 [IBIT](IMPORTANT): massDefault: 1.211655 cm 2025-05-19T17:28:00.487Z,1747675680.487 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2025-05-19T17:28:00.487Z,1747675680.487 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2025-05-19T17:28:00.487Z,1747675680.487 [IBIT](IMPORTANT): IBIT PASSED 2025-05-19T17:28:00.888Z,1747675680.888 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:28:00.888Z,1747675680.888 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:28:00.888Z,1747675680.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:28:00.888Z,1747675680.888 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:28:01.285Z,1747675681.285 [Default:CheckIn:D] Stopped 2025-05-19T17:28:01.285Z,1747675681.285 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.973112 min 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn:E] Stopped 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn] Stopped 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn](INFO): Running loop #29 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn] Running Loop=29 2025-05-19T17:28:01.687Z,1747675681.687 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:28:01.688Z,1747675681.688 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:28:05.717Z,1747675685.717 [NAL9602](INFO): SBD MO Status=0, MOMSN=63154, MT Status=0, MTMSN=0 2025-05-19T17:28:05.717Z,1747675685.717 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:28:06.930Z,1747675686.930 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172806.00,A,3648.16374,N,12147.21290,W,0.097,0.00,190525,,,A*75 2025-05-19T17:28:06.932Z,1747675686.932 [NAL9602](INFO): GPS fix at 20250519T172806: (36.802729, -121.786882) 2025-05-19T17:28:06.943Z,1747675686.943 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:28:06.943Z,1747675686.943 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:28:13.564Z,1747675693.564 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0091.lzma 2025-05-19T17:28:14.567Z,1747675694.567 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0091.lzma.bak 2025-05-19T17:28:14.567Z,1747675694.567 [DataOverHttps](INFO): SBD MOMSN=24921317 2025-05-19T17:28:34.187Z,1747675714.187 [DataOverHttps](INFO): Sending 811 bytes from file Logs/20250519T143346/Express0092.lzma 2025-05-19T17:28:35.189Z,1747675715.189 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0092.lzma.bak 2025-05-19T17:28:35.189Z,1747675715.189 [DataOverHttps](INFO): SBD MOMSN=24921326 2025-05-19T17:28:39.718Z,1747675719.718 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:28:54.901Z,1747675734.901 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250519T143346/Express0095.lzma 2025-05-19T17:28:55.903Z,1747675735.903 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0095.lzma.bak 2025-05-19T17:28:55.903Z,1747675735.903 [DataOverHttps](INFO): SBD MOMSN=24921357 2025-05-19T17:28:57.205Z,1747675737.205 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:28:57.205Z,1747675737.205 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:28:57.206Z,1747675737.206 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:33:57.748Z,1747676037.748 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:33:57.748Z,1747676037.748 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:33:57.748Z,1747676037.748 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:33:57.748Z,1747676037.748 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:33:58.166Z,1747676038.166 [Default:CheckIn:D] Stopped 2025-05-19T17:33:58.166Z,1747676038.166 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:33:58.550Z,1747676038.550 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.921126 min 2025-05-19T17:33:58.550Z,1747676038.550 [Default:CheckIn:E] Stopped 2025-05-19T17:33:58.550Z,1747676038.550 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:33:58.550Z,1747676038.550 [Default:CheckIn] Stopped 2025-05-19T17:33:58.550Z,1747676038.550 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:33:58.551Z,1747676038.551 [Default:CheckIn](INFO): Running loop #30 2025-05-19T17:33:58.551Z,1747676038.551 [Default:CheckIn] Running Loop=30 2025-05-19T17:33:58.551Z,1747676038.551 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:33:58.551Z,1747676038.551 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:34:00.580Z,1747676040.580 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173359.00,A,3648.16457,N,12147.21314,W,0.039,0.00,190525,,,A*7A 2025-05-19T17:34:00.582Z,1747676040.582 [NAL9602](INFO): GPS fix at 20250519T173359: (36.802743, -121.786886) 2025-05-19T17:34:00.593Z,1747676040.593 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:34:00.593Z,1747676040.593 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:34:08.101Z,1747676048.101 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0097.lzma 2025-05-19T17:34:09.103Z,1747676049.103 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0097.lzma.bak 2025-05-19T17:34:09.103Z,1747676049.103 [DataOverHttps](INFO): SBD MOMSN=24921449 2025-05-19T17:34:28.586Z,1747676068.586 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250519T143346/Express0098.lzma 2025-05-19T17:34:28.900Z,1747676068.900 [NAL9602](INFO): SBD MO Status=0, MOMSN=63155, MT Status=0, MTMSN=0 2025-05-19T17:34:28.900Z,1747676068.900 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:34:29.587Z,1747676069.587 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0098.lzma.bak 2025-05-19T17:34:29.587Z,1747676069.587 [DataOverHttps](INFO): SBD MOMSN=24921452 2025-05-19T17:34:30.925Z,1747676070.925 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:34:30.925Z,1747676070.925 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:34:30.925Z,1747676070.925 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:34:59.598Z,1747676099.598 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:37:06.857Z,1747676226.857 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:37:18.575Z,1747676238.575 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:37:30.694Z,1747676250.694 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:37:42.814Z,1747676262.814 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:37:54.528Z,1747676274.528 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:38:06.246Z,1747676286.246 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:38:17.557Z,1747676297.557 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:38:29.678Z,1747676309.678 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:39:31.520Z,1747676371.520 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:39:31.520Z,1747676371.520 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:39:31.520Z,1747676371.520 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:39:31.520Z,1747676371.520 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:39:31.933Z,1747676371.933 [Default:CheckIn:D] Stopped 2025-05-19T17:39:31.933Z,1747676371.933 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:39:32.316Z,1747676372.316 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.483903 min 2025-05-19T17:39:32.317Z,1747676372.317 [Default:CheckIn:E] Stopped 2025-05-19T17:39:32.317Z,1747676372.317 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:39:32.317Z,1747676372.317 [Default:CheckIn] Stopped 2025-05-19T17:39:32.317Z,1747676372.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:39:32.317Z,1747676372.317 [Default:CheckIn](INFO): Running loop #31 2025-05-19T17:39:32.317Z,1747676372.317 [Default:CheckIn] Running Loop=31 2025-05-19T17:39:32.317Z,1747676372.317 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:39:32.318Z,1747676372.318 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:39:34.322Z,1747676374.322 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173933.00,A,3648.16381,N,12147.21284,W,0.058,0.00,190525,,,A*7F 2025-05-19T17:39:34.324Z,1747676374.324 [NAL9602](INFO): GPS fix at 20250519T173933: (36.802730, -121.786881) 2025-05-19T17:39:34.336Z,1747676374.336 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:39:34.336Z,1747676374.336 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:39:41.689Z,1747676381.689 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0100.lzma 2025-05-19T17:39:42.691Z,1747676382.691 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0100.lzma.bak 2025-05-19T17:39:42.691Z,1747676382.691 [DataOverHttps](INFO): SBD MOMSN=24921466 2025-05-19T17:39:56.548Z,1747676396.548 [NAL9602](INFO): SBD MO Status=0, MOMSN=63156, MT Status=0, MTMSN=0 2025-05-19T17:39:56.548Z,1747676396.548 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:39:58.861Z,1747676398.861 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0101.lzma 2025-05-19T17:39:59.863Z,1747676399.863 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0101.lzma.bak 2025-05-19T17:39:59.863Z,1747676399.863 [DataOverHttps](INFO): SBD MOMSN=24921472 2025-05-19T17:40:01.059Z,1747676401.059 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:40:01.059Z,1747676401.059 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:40:01.059Z,1747676401.059 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:40:27.286Z,1747676427.286 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:41:05.663Z,1747676465.663 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:41:18.993Z,1747676478.993 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:41:32.326Z,1747676492.326 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:41:45.659Z,1747676505.659 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:41:58.989Z,1747676518.989 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:42:12.321Z,1747676532.321 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:42:26.057Z,1747676546.057 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:42:40.198Z,1747676560.198 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:42:53.529Z,1747676573.529 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:43:07.265Z,1747676587.265 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:43:21.462Z,1747676601.462 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:45:01.639Z,1747676701.639 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:45:01.639Z,1747676701.639 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:45:01.639Z,1747676701.639 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:45:01.639Z,1747676701.639 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:45:02.021Z,1747676702.021 [Default:CheckIn:D] Stopped 2025-05-19T17:45:02.021Z,1747676702.021 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:45:02.427Z,1747676702.427 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.985384 min 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn:E] Stopped 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn] Stopped 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn](INFO): Running loop #32 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn] Running Loop=32 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:45:02.428Z,1747676702.428 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:45:04.436Z,1747676704.436 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174503.00,A,3648.16353,N,12147.21273,W,0.039,0.00,190525,,,A*77 2025-05-19T17:45:04.439Z,1747676704.439 [NAL9602](INFO): GPS fix at 20250519T174503: (36.802726, -121.786879) 2025-05-19T17:45:04.467Z,1747676704.467 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:45:04.467Z,1747676704.467 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:45:12.121Z,1747676712.121 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0103.lzma 2025-05-19T17:45:13.123Z,1747676713.123 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0103.lzma.bak 2025-05-19T17:45:13.123Z,1747676713.123 [DataOverHttps](INFO): SBD MOMSN=24921564 2025-05-19T17:45:25.484Z,1747676725.484 [NAL9602](INFO): SBD MO Status=0, MOMSN=63157, MT Status=0, MTMSN=0 2025-05-19T17:45:25.484Z,1747676725.484 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:45:29.469Z,1747676729.469 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0104.lzma 2025-05-19T17:45:30.471Z,1747676730.471 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0104.lzma.bak 2025-05-19T17:45:30.471Z,1747676730.471 [DataOverHttps](INFO): SBD MOMSN=24921577 2025-05-19T17:45:31.548Z,1747676731.548 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:45:31.548Z,1747676731.548 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:45:31.548Z,1747676731.548 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:45:56.166Z,1747676756.166 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:48:38.979Z,1747676918.979 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-05-19T17:50:32.124Z,1747677032.124 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:50:32.124Z,1747677032.124 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:50:32.124Z,1747677032.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:50:32.124Z,1747677032.124 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:50:32.520Z,1747677032.520 [Default:CheckIn:D] Stopped 2025-05-19T17:50:32.520Z,1747677032.520 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:50:32.928Z,1747677032.928 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.493701 min 2025-05-19T17:50:32.928Z,1747677032.928 [Default:CheckIn:E] Stopped 2025-05-19T17:50:32.929Z,1747677032.929 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:50:32.929Z,1747677032.929 [Default:CheckIn] Stopped 2025-05-19T17:50:32.929Z,1747677032.929 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:50:32.929Z,1747677032.929 [Default:CheckIn](INFO): Running loop #33 2025-05-19T17:50:32.929Z,1747677032.929 [Default:CheckIn] Running Loop=33 2025-05-19T17:50:32.929Z,1747677032.929 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:50:32.929Z,1747677032.929 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:50:34.941Z,1747677034.941 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175034.00,A,3648.16364,N,12147.21404,W,0.039,0.00,190525,,,A*75 2025-05-19T17:50:34.943Z,1747677034.943 [NAL9602](INFO): GPS fix at 20250519T175034: (36.802727, -121.786901) 2025-05-19T17:50:34.954Z,1747677034.954 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:50:34.955Z,1747677034.955 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:50:35.749Z,1747677035.749 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:50:35.749Z,1747677035.749 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:50:35.749Z,1747677035.749 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T17:50:43.817Z,1747677043.817 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:50:48.672Z,1747677048.672 [NAL9602](INFO): SBD MO Status=0, MOMSN=63158, MT Status=0, MTMSN=0 2025-05-19T17:50:48.672Z,1747677048.672 [NAL9602](INFO): No messages in MT queue 2025-05-19T17:50:57.165Z,1747677057.165 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:51:10.908Z,1747677070.908 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:51:19.406Z,1747677079.406 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:51:24.234Z,1747677084.234 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:51:37.565Z,1747677097.565 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:51:50.897Z,1747677110.897 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:52:04.229Z,1747677124.229 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:52:17.965Z,1747677137.965 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:52:32.105Z,1747677152.105 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:52:45.438Z,1747677165.438 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:52:59.577Z,1747677179.577 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T17:55:36.348Z,1747677336.348 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T17:55:36.348Z,1747677336.348 [Default:CheckIn:C.Wait] Stopped 2025-05-19T17:55:36.348Z,1747677336.348 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T17:55:36.348Z,1747677336.348 [Default:CheckIn:D] Running Loop=1 2025-05-19T17:55:36.746Z,1747677336.746 [Default:CheckIn:D] Stopped 2025-05-19T17:55:36.746Z,1747677336.746 [Default:CheckIn:E] Running Loop=1 2025-05-19T17:55:37.153Z,1747677337.153 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.564128 min 2025-05-19T17:55:37.153Z,1747677337.153 [Default:CheckIn:E] Stopped 2025-05-19T17:55:37.154Z,1747677337.154 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T17:55:37.154Z,1747677337.154 [Default:CheckIn] Stopped 2025-05-19T17:55:37.154Z,1747677337.154 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T17:55:37.154Z,1747677337.154 [Default:CheckIn](INFO): Running loop #34 2025-05-19T17:55:37.154Z,1747677337.154 [Default:CheckIn] Running Loop=34 2025-05-19T17:55:37.154Z,1747677337.154 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T17:55:37.154Z,1747677337.154 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T17:55:39.170Z,1747677339.170 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175538.00,A,3648.16232,N,12147.20892,W,0.078,0.00,190525,,,D*7C 2025-05-19T17:55:39.172Z,1747677339.172 [NAL9602](INFO): GPS fix at 20250519T175538: (36.802705, -121.786815) 2025-05-19T17:55:39.183Z,1747677339.183 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T17:55:39.183Z,1747677339.183 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T17:55:46.577Z,1747677346.577 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0106.lzma 2025-05-19T17:55:47.579Z,1747677347.579 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0106.lzma.bak 2025-05-19T17:55:47.580Z,1747677347.580 [DataOverHttps](INFO): SBD MOMSN=24921697 2025-05-19T17:55:54.925Z,1747677354.925 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=63159, MT Status=1, MTMSN=3901 2025-05-19T17:55:54.925Z,1747677354.925 [NAL9602](INFO): Data available in MT queue 2025-05-19T17:55:55.426Z,1747677355.426 [NAL9602](INFO): Received command: failc 2025-05-19T17:55:55.486Z,1747677355.486 [CommandExec](IMPORTANT): got command failComponent 2025-05-19T17:55:55.486Z,1747677355.486 [CommandExec](IMPORTANT): Failed components: 2025-05-19T17:55:55.486Z,1747677355.486 [CommandExec](IMPORTANT): No failed Components. 2025-05-19T17:56:03.501Z,1747677363.501 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0109.lzma 2025-05-19T17:56:04.503Z,1747677364.503 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0109.lzma.bak 2025-05-19T17:56:04.504Z,1747677364.504 [DataOverHttps](INFO): SBD MOMSN=24921700 2025-05-19T17:56:23.225Z,1747677383.225 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250519T143346/Express0107.lzma 2025-05-19T17:56:24.227Z,1747677384.227 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0107.lzma.bak 2025-05-19T17:56:24.227Z,1747677384.227 [DataOverHttps](INFO): SBD MOMSN=24921703 2025-05-19T17:56:26.076Z,1747677386.076 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T17:56:41.049Z,1747677401.049 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250519T143346/Express0110.lzma 2025-05-19T17:56:42.051Z,1747677402.051 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0110.lzma.bak 2025-05-19T17:56:42.051Z,1747677402.051 [DataOverHttps](INFO): SBD MOMSN=24921707 2025-05-19T17:56:43.464Z,1747677403.464 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T17:56:43.464Z,1747677403.464 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T17:56:43.464Z,1747677403.464 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:00:17.721Z,1747677617.721 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:00:31.110Z,1747677631.110 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:00:44.874Z,1747677644.874 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:00:58.229Z,1747677658.229 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:01:11.966Z,1747677671.966 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:01:26.509Z,1747677686.509 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:01:40.649Z,1747677700.649 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:01:43.913Z,1747677703.913 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:01:43.913Z,1747677703.913 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:01:43.913Z,1747677703.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:01:43.913Z,1747677703.913 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:01:44.323Z,1747677704.323 [Default:CheckIn:D] Stopped 2025-05-19T18:01:44.323Z,1747677704.323 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:01:44.704Z,1747677704.704 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.690413 min 2025-05-19T18:01:44.704Z,1747677704.704 [Default:CheckIn:E] Stopped 2025-05-19T18:01:44.704Z,1747677704.704 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:01:44.705Z,1747677704.705 [Default:CheckIn] Stopped 2025-05-19T18:01:44.705Z,1747677704.705 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:01:44.706Z,1747677704.706 [Default:CheckIn](INFO): Running loop #35 2025-05-19T18:01:44.706Z,1747677704.706 [Default:CheckIn] Running Loop=35 2025-05-19T18:01:44.706Z,1747677704.706 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:01:44.706Z,1747677704.706 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:01:46.715Z,1747677706.715 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180146.00,A,3648.16295,N,12147.21293,W,0.078,0.00,190525,,,D*7C 2025-05-19T18:01:46.717Z,1747677706.717 [NAL9602](INFO): GPS fix at 20250519T180146: (36.802716, -121.786882) 2025-05-19T18:01:46.727Z,1747677706.727 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:01:46.728Z,1747677706.728 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:01:54.387Z,1747677714.387 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:01:54.484Z,1747677714.484 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0112.lzma 2025-05-19T18:01:55.483Z,1747677715.483 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0112.lzma.bak 2025-05-19T18:01:55.483Z,1747677715.483 [DataOverHttps](INFO): SBD MOMSN=24921729 2025-05-19T18:02:08.529Z,1747677728.529 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:02:11.849Z,1747677731.849 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20250519T143346/Express0113.lzma 2025-05-19T18:02:12.851Z,1747677732.851 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0113.lzma.bak 2025-05-19T18:02:12.851Z,1747677732.851 [DataOverHttps](INFO): SBD MOMSN=24921734 2025-05-19T18:02:14.198Z,1747677734.198 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:02:14.198Z,1747677734.198 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:02:14.198Z,1747677734.198 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:02:17.016Z,1747677737.016 [NAL9602](INFO): SBD MO Status=0, MOMSN=63160, MT Status=0, MTMSN=0 2025-05-19T18:02:17.016Z,1747677737.016 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:02:21.908Z,1747677741.908 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:02:35.651Z,1747677755.651 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-05-19T18:02:47.488Z,1747677767.488 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:07:01.725Z,1747678021.725 [BPC1](FAULT): Battery stick #31 (s/n: 029D) reported TERMINATE_CHARGE_ALARM. Status code: 0x40C0. 2025-05-19T18:07:01.726Z,1747678021.726 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2025-05-19T18:07:01.729Z,1747678021.729 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2025-05-19T18:07:14.669Z,1747678034.669 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:07:14.669Z,1747678034.669 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:07:14.669Z,1747678034.669 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:07:14.669Z,1747678034.669 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:07:15.075Z,1747678035.075 [Default:CheckIn:D] Stopped 2025-05-19T18:07:15.075Z,1747678035.075 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:07:15.487Z,1747678035.487 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 209.202946 min 2025-05-19T18:07:15.487Z,1747678035.487 [Default:CheckIn:E] Stopped 2025-05-19T18:07:15.487Z,1747678035.487 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:07:15.488Z,1747678035.488 [Default:CheckIn] Stopped 2025-05-19T18:07:15.488Z,1747678035.488 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:07:15.488Z,1747678035.488 [Default:CheckIn](INFO): Running loop #36 2025-05-19T18:07:15.488Z,1747678035.488 [Default:CheckIn] Running Loop=36 2025-05-19T18:07:15.488Z,1747678035.488 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:07:15.488Z,1747678035.488 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:07:17.488Z,1747678037.488 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180716.00,A,3648.33289,N,12147.12221,W,2.780,7.51,190525,,,D*7D 2025-05-19T18:07:17.491Z,1747678037.491 [NAL9602](INFO): GPS fix at 20250519T180716: (36.805548, -121.785370) 2025-05-19T18:07:17.517Z,1747678037.517 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:07:17.518Z,1747678037.518 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:07:24.641Z,1747678044.641 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20250519T143346/Courier0115.lzma 2025-05-19T18:07:25.644Z,1747678045.644 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0115.lzma.bak 2025-05-19T18:07:25.644Z,1747678045.644 [DataOverHttps](INFO): SBD MOMSN=24921803 2025-05-19T18:07:41.721Z,1747678061.721 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20250519T143346/Express0116.lzma 2025-05-19T18:07:42.535Z,1747678062.535 [NAL9602](INFO): SBD MO Status=2, MOMSN=63161, MT Status=2, MTMSN=0 2025-05-19T18:07:42.536Z,1747678062.536 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T18:07:42.723Z,1747678062.723 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0116.lzma.bak 2025-05-19T18:07:42.723Z,1747678062.723 [DataOverHttps](INFO): SBD MOMSN=24921806 2025-05-19T18:07:43.776Z,1747678063.776 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:07:43.776Z,1747678063.776 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:07:43.776Z,1747678063.776 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:08:00.736Z,1747678080.736 [NAL9602](INFO): SBD MO Status=0, MOMSN=63161, MT Status=0, MTMSN=0 2025-05-19T18:08:00.736Z,1747678080.736 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:08:31.487Z,1747678111.487 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:12:44.226Z,1747678364.226 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:12:44.226Z,1747678364.226 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:12:44.226Z,1747678364.226 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:12:44.226Z,1747678364.226 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:12:44.625Z,1747678364.625 [Default:CheckIn:D] Stopped 2025-05-19T18:12:44.625Z,1747678364.625 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:12:45.031Z,1747678365.031 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 214.695443 min 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn:E] Stopped 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn] Stopped 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn](INFO): Running loop #37 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn] Running Loop=37 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:12:45.032Z,1747678365.032 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:12:47.048Z,1747678367.048 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181246.00,A,3648.47985,N,12147.27770,W,4.626,237.42,190525,,,A*72 2025-05-19T18:12:47.061Z,1747678367.061 [NAL9602](INFO): GPS fix at 20250519T181246: (36.807997, -121.787962) 2025-05-19T18:12:47.071Z,1747678367.071 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:12:47.072Z,1747678367.072 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:12:57.272Z,1747678377.272 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0118.lzma 2025-05-19T18:12:57.616Z,1747678377.616 [NAL9602](INFO): SBD MO Status=0, MOMSN=63162, MT Status=0, MTMSN=0 2025-05-19T18:12:57.616Z,1747678377.616 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:12:58.275Z,1747678378.275 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0118.lzma.bak 2025-05-19T18:12:58.276Z,1747678378.276 [DataOverHttps](INFO): SBD MOMSN=24921836 2025-05-19T18:13:14.489Z,1747678394.489 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250519T143346/Express0119.lzma 2025-05-19T18:13:15.491Z,1747678395.491 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0119.lzma.bak 2025-05-19T18:13:15.491Z,1747678395.491 [DataOverHttps](INFO): SBD MOMSN=24921882 2025-05-19T18:13:16.628Z,1747678396.628 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:13:16.628Z,1747678396.628 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:13:16.628Z,1747678396.628 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:13:28.318Z,1747678408.318 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:18:17.378Z,1747678697.378 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:18:17.379Z,1747678697.379 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:18:17.379Z,1747678697.379 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:18:17.379Z,1747678697.379 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:18:17.792Z,1747678697.792 [Default:CheckIn:D] Stopped 2025-05-19T18:18:17.792Z,1747678697.792 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 220.248226 min 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn:E] Stopped 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn] Stopped 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn](INFO): Running loop #38 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn] Running Loop=38 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:18:18.186Z,1747678698.186 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:18:20.205Z,1747678700.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181819.00,A,3648.31043,N,12147.65505,W,1.769,262.35,190525,,,A*79 2025-05-19T18:18:20.208Z,1747678700.208 [NAL9602](INFO): GPS fix at 20250519T181819: (36.805174, -121.794251) 2025-05-19T18:18:20.227Z,1747678700.227 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:18:20.227Z,1747678700.227 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:18:30.305Z,1747678710.305 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0121.lzma 2025-05-19T18:18:31.307Z,1747678711.307 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0121.lzma.bak 2025-05-19T18:18:31.307Z,1747678711.307 [DataOverHttps](INFO): SBD MOMSN=24921899 2025-05-19T18:18:32.815Z,1747678712.815 [NAL9602](INFO): SBD MO Status=0, MOMSN=63163, MT Status=0, MTMSN=0 2025-05-19T18:18:32.815Z,1747678712.815 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:18:47.266Z,1747678727.266 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250519T143346/Express0122.lzma 2025-05-19T18:18:48.267Z,1747678728.267 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0122.lzma.bak 2025-05-19T18:18:48.267Z,1747678728.267 [DataOverHttps](INFO): SBD MOMSN=24921902 2025-05-19T18:18:49.404Z,1747678729.404 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:18:49.404Z,1747678729.404 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:18:49.404Z,1747678729.404 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:19:03.586Z,1747678743.586 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:23:50.068Z,1747679030.068 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:23:50.068Z,1747679030.068 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:23:50.068Z,1747679030.068 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:23:50.068Z,1747679030.068 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:23:50.469Z,1747679030.469 [Default:CheckIn:D] Stopped 2025-05-19T18:23:50.469Z,1747679030.469 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:23:50.878Z,1747679030.878 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 225.792855 min 2025-05-19T18:23:50.878Z,1747679030.878 [Default:CheckIn:E] Stopped 2025-05-19T18:23:50.879Z,1747679030.879 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:23:50.879Z,1747679030.879 [Default:CheckIn] Stopped 2025-05-19T18:23:50.879Z,1747679030.879 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:23:50.879Z,1747679030.879 [Default:CheckIn](INFO): Running loop #39 2025-05-19T18:23:50.879Z,1747679030.879 [Default:CheckIn] Running Loop=39 2025-05-19T18:23:50.879Z,1747679030.879 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:23:50.879Z,1747679030.879 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:23:52.886Z,1747679032.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182352.00,A,3648.25787,N,12148.11971,W,4.199,263.72,190525,,,A*79 2025-05-19T18:23:52.888Z,1747679032.888 [NAL9602](INFO): GPS fix at 20250519T182352: (36.804298, -121.801995) 2025-05-19T18:23:52.911Z,1747679032.911 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:23:52.911Z,1747679032.911 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:24:00.361Z,1747679040.361 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0124.lzma 2025-05-19T18:24:01.200Z,1747679041.200 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0124.lzma.bak 2025-05-19T18:24:01.200Z,1747679041.200 [DataOverHttps](INFO): SBD MOMSN=24921964 2025-05-19T18:24:10.664Z,1747679050.664 [NAL9602](INFO): SBD MO Status=0, MOMSN=63164, MT Status=0, MTMSN=0 2025-05-19T18:24:10.664Z,1747679050.664 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:24:17.241Z,1747679057.241 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250519T143346/Express0125.lzma 2025-05-19T18:24:18.243Z,1747679058.243 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0125.lzma.bak 2025-05-19T18:24:18.244Z,1747679058.244 [DataOverHttps](INFO): SBD MOMSN=24921967 2025-05-19T18:24:19.596Z,1747679059.596 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:24:19.596Z,1747679059.596 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:24:19.596Z,1747679059.596 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:24:41.458Z,1747679081.458 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:29:20.316Z,1747679360.316 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:29:20.316Z,1747679360.316 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:29:20.316Z,1747679360.316 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:29:20.316Z,1747679360.316 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:29:20.726Z,1747679360.726 [Default:CheckIn:D] Stopped 2025-05-19T18:29:20.726Z,1747679360.726 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 231.297135 min 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn:E] Stopped 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn] Stopped 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn](INFO): Running loop #40 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn] Running Loop=40 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:29:21.122Z,1747679361.122 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:29:23.140Z,1747679363.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182922.00,A,3648.20646,N,12148.59097,W,4.354,244.62,190525,,,A*77 2025-05-19T18:29:23.142Z,1747679363.142 [NAL9602](INFO): GPS fix at 20250519T182922: (36.803441, -121.809849) 2025-05-19T18:29:23.153Z,1747679363.153 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:29:23.153Z,1747679363.153 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:29:36.070Z,1747679376.070 [NAL9602](INFO): SBD MO Status=0, MOMSN=63165, MT Status=0, MTMSN=0 2025-05-19T18:29:36.070Z,1747679376.070 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:30:06.767Z,1747679406.767 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:30:11.726Z,1747679411.726 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0127.lzma 2025-05-19T18:30:12.727Z,1747679412.727 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0127.lzma.bak 2025-05-19T18:30:12.727Z,1747679412.727 [DataOverHttps](INFO): SBD MOMSN=24921987 2025-05-19T18:30:32.184Z,1747679432.184 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20250519T143346/Express0128.lzma 2025-05-19T18:30:33.183Z,1747679433.183 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0128.lzma.bak 2025-05-19T18:30:33.183Z,1747679433.183 [DataOverHttps](INFO): SBD MOMSN=24921990 2025-05-19T18:30:34.286Z,1747679434.286 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:30:34.286Z,1747679434.286 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:30:34.286Z,1747679434.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:33:07.649Z,1747679587.649 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:33:38.789Z,1747679618.789 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:34:09.925Z,1747679649.925 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:34:41.049Z,1747679681.049 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:34:43.058Z,1747679683.058 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.235413 2025-05-19T18:35:34.856Z,1747679734.856 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:35:34.856Z,1747679734.856 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:35:34.856Z,1747679734.856 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:35:34.856Z,1747679734.856 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:35:35.263Z,1747679735.263 [Default:CheckIn:D] Stopped 2025-05-19T18:35:35.263Z,1747679735.263 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:35:35.676Z,1747679735.676 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 237.539421 min 2025-05-19T18:35:35.676Z,1747679735.676 [Default:CheckIn:E] Stopped 2025-05-19T18:35:35.677Z,1747679735.677 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:35:35.677Z,1747679735.677 [Default:CheckIn] Stopped 2025-05-19T18:35:35.677Z,1747679735.677 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:35:35.677Z,1747679735.677 [Default:CheckIn](INFO): Running loop #41 2025-05-19T18:35:35.677Z,1747679735.677 [Default:CheckIn] Running Loop=41 2025-05-19T18:35:35.677Z,1747679735.677 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:35:35.677Z,1747679735.677 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:35:37.676Z,1747679737.676 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183536.00,A,3648.19727,N,12149.00141,W,4.238,231.83,190525,,,A*72 2025-05-19T18:35:37.679Z,1747679737.679 [NAL9602](INFO): GPS fix at 20250519T183536: (36.803288, -121.816690) 2025-05-19T18:35:37.694Z,1747679737.694 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:35:37.694Z,1747679737.694 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:35:42.309Z,1747679742.309 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:36:12.879Z,1747679772.879 [NAL9602](INFO): SBD MO Status=1, MOMSN=63166, MT Status=0, MTMSN=0 2025-05-19T18:36:12.931Z,1747679772.931 [NAL9602](INFO): Sent 72 bytes from file Logs/20250519T143346/Courier0130.lzma 2025-05-19T18:36:12.931Z,1747679772.931 [NAL9602](INFO): Packets left to send: 0 2025-05-19T18:36:13.457Z,1747679773.457 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:36:24.632Z,1747679784.632 [NAL9602](INFO): SBD MO Status=1, MOMSN=63167, MT Status=0, MTMSN=0 2025-05-19T18:36:24.682Z,1747679784.682 [NAL9602](INFO): Sent 163 bytes from file Logs/20250519T143346/Express0131.lzma 2025-05-19T18:36:24.682Z,1747679784.682 [NAL9602](INFO): Packets left to send: 0 2025-05-19T18:36:33.530Z,1747679793.530 [NAL9602](INFO): SBD MO Status=0, MOMSN=63168, MT Status=0, MTMSN=0 2025-05-19T18:36:33.610Z,1747679793.610 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:36:33.610Z,1747679793.610 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:36:33.610Z,1747679793.610 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:36:44.593Z,1747679804.593 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:37:04.223Z,1747679824.223 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:37:15.717Z,1747679835.717 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:37:46.841Z,1747679866.841 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:38:29.522Z,1747679909.522 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003234 2025-05-19T18:41:34.300Z,1747680094.300 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:41:34.300Z,1747680094.300 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:41:34.300Z,1747680094.300 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:41:34.300Z,1747680094.300 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:41:34.698Z,1747680094.698 [Default:CheckIn:D] Stopped 2025-05-19T18:41:34.698Z,1747680094.698 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.529997 min 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn:E] Stopped 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn] Stopped 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn](INFO): Running loop #42 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn] Running Loop=42 2025-05-19T18:41:35.099Z,1747680095.099 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:41:35.100Z,1747680095.100 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:41:37.110Z,1747680097.110 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184136.00,A,3648.31059,N,12149.43462,W,4.199,309.45,190525,,,D*7B 2025-05-19T18:41:37.112Z,1747680097.112 [NAL9602](INFO): GPS fix at 20250519T184136: (36.805177, -121.823910) 2025-05-19T18:41:37.139Z,1747680097.139 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:41:37.139Z,1747680097.139 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:41:53.153Z,1747680113.153 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-05-19T18:42:01.352Z,1747680121.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=63169, MT Status=2, MTMSN=0 2025-05-19T18:42:01.352Z,1747680121.352 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T18:42:01.741Z,1747680121.741 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0133.lzma 2025-05-19T18:42:02.743Z,1747680122.743 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0133.lzma.bak 2025-05-19T18:42:02.743Z,1747680122.743 [DataOverHttps](INFO): SBD MOMSN=24922081 2025-05-19T18:42:22.376Z,1747680142.376 [NAL9602](INFO): SBD MO Status=2, MOMSN=63169, MT Status=2, MTMSN=0 2025-05-19T18:42:22.377Z,1747680142.377 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-05-19T18:42:22.758Z,1747680142.758 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250519T143346/Express0134.lzma 2025-05-19T18:42:23.760Z,1747680143.760 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0134.lzma.bak 2025-05-19T18:42:23.760Z,1747680143.760 [DataOverHttps](INFO): SBD MOMSN=24922087 2025-05-19T18:42:24.829Z,1747680144.829 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:42:24.829Z,1747680144.829 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:42:24.829Z,1747680144.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:42:36.532Z,1747680156.532 [NAL9602](INFO): SBD MO Status=0, MOMSN=63169, MT Status=0, MTMSN=0 2025-05-19T18:42:36.532Z,1747680156.532 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:43:07.250Z,1747680187.250 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:43:56.217Z,1747680236.217 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-05-19T18:47:25.394Z,1747680445.394 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:47:25.394Z,1747680445.394 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:47:25.394Z,1747680445.394 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:47:25.394Z,1747680445.394 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:47:25.803Z,1747680445.803 [Default:CheckIn:D] Stopped 2025-05-19T18:47:25.803Z,1747680445.803 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:47:26.221Z,1747680446.221 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 249.381755 min 2025-05-19T18:47:26.221Z,1747680446.221 [Default:CheckIn:E] Stopped 2025-05-19T18:47:26.221Z,1747680446.221 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:47:26.222Z,1747680446.222 [Default:CheckIn] Stopped 2025-05-19T18:47:26.222Z,1747680446.222 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:47:26.222Z,1747680446.222 [Default:CheckIn](INFO): Running loop #43 2025-05-19T18:47:26.222Z,1747680446.222 [Default:CheckIn] Running Loop=43 2025-05-19T18:47:26.222Z,1747680446.222 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:47:26.222Z,1747680446.222 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:47:28.220Z,1747680448.220 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184727.00,A,3648.35134,N,12149.40249,W,0.797,103.12,190525,,,D*79 2025-05-19T18:47:28.222Z,1747680448.222 [NAL9602](INFO): GPS fix at 20250519T184727: (36.805856, -121.823375) 2025-05-19T18:47:28.233Z,1747680448.233 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:47:28.233Z,1747680448.233 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:47:35.849Z,1747680455.849 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0136.lzma 2025-05-19T18:47:36.851Z,1747680456.851 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0136.lzma.bak 2025-05-19T18:47:36.851Z,1747680456.851 [DataOverHttps](INFO): SBD MOMSN=24922154 2025-05-19T18:47:40.740Z,1747680460.740 [NAL9602](INFO): SBD MO Status=0, MOMSN=63170, MT Status=0, MTMSN=0 2025-05-19T18:47:40.740Z,1747680460.740 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:47:52.937Z,1747680472.937 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250519T143346/Express0137.lzma 2025-05-19T18:47:53.939Z,1747680473.939 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0137.lzma.bak 2025-05-19T18:47:53.939Z,1747680473.939 [DataOverHttps](INFO): SBD MOMSN=24922160 2025-05-19T18:47:55.403Z,1747680475.403 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:47:55.403Z,1747680475.403 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:47:55.403Z,1747680475.403 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:48:11.446Z,1747680491.446 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:52:55.903Z,1747680775.903 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:52:55.903Z,1747680775.903 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:52:55.903Z,1747680775.903 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:52:55.904Z,1747680775.904 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:52:56.295Z,1747680776.295 [Default:CheckIn:D] Stopped 2025-05-19T18:52:56.295Z,1747680776.295 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:52:56.681Z,1747680776.681 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 254.889958 min 2025-05-19T18:52:56.681Z,1747680776.681 [Default:CheckIn:E] Stopped 2025-05-19T18:52:56.681Z,1747680776.681 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:52:56.681Z,1747680776.681 [Default:CheckIn] Stopped 2025-05-19T18:52:56.682Z,1747680776.682 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:52:56.682Z,1747680776.682 [Default:CheckIn](INFO): Running loop #44 2025-05-19T18:52:56.682Z,1747680776.682 [Default:CheckIn] Running Loop=44 2025-05-19T18:52:56.682Z,1747680776.682 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:52:56.682Z,1747680776.682 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:52:58.695Z,1747680778.695 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185257.00,A,3648.34880,N,12149.34008,W,0.467,105.32,190525,,,D*71 2025-05-19T18:52:58.698Z,1747680778.698 [NAL9602](INFO): GPS fix at 20250519T185257: (36.805813, -121.822335) 2025-05-19T18:52:58.708Z,1747680778.708 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:52:58.708Z,1747680778.708 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:53:06.585Z,1747680786.585 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0139.lzma 2025-05-19T18:53:07.588Z,1747680787.588 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0139.lzma.bak 2025-05-19T18:53:07.589Z,1747680787.589 [DataOverHttps](INFO): SBD MOMSN=24922174 2025-05-19T18:53:20.524Z,1747680800.524 [NAL9602](INFO): SBD MO Status=0, MOMSN=63171, MT Status=0, MTMSN=0 2025-05-19T18:53:20.524Z,1747680800.524 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:53:23.677Z,1747680803.677 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20250519T143346/Express0140.lzma 2025-05-19T18:53:24.680Z,1747680804.680 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0140.lzma.bak 2025-05-19T18:53:24.680Z,1747680804.680 [DataOverHttps](INFO): SBD MOMSN=24922180 2025-05-19T18:53:25.768Z,1747680805.768 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:53:25.768Z,1747680805.768 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:53:25.768Z,1747680805.768 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:53:51.208Z,1747680831.208 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T18:58:26.357Z,1747681106.357 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T18:58:26.373Z,1747681106.373 [Default:CheckIn:C.Wait] Stopped 2025-05-19T18:58:26.373Z,1747681106.373 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T18:58:26.373Z,1747681106.373 [Default:CheckIn:D] Running Loop=1 2025-05-19T18:58:26.756Z,1747681106.756 [Default:CheckIn:D] Stopped 2025-05-19T18:58:26.756Z,1747681106.756 [Default:CheckIn:E] Running Loop=1 2025-05-19T18:58:27.166Z,1747681107.166 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 260.397640 min 2025-05-19T18:58:27.166Z,1747681107.166 [Default:CheckIn:E] Stopped 2025-05-19T18:58:27.166Z,1747681107.166 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T18:58:27.166Z,1747681107.166 [Default:CheckIn] Stopped 2025-05-19T18:58:27.166Z,1747681107.166 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T18:58:27.167Z,1747681107.167 [Default:CheckIn](INFO): Running loop #45 2025-05-19T18:58:27.167Z,1747681107.167 [Default:CheckIn] Running Loop=45 2025-05-19T18:58:27.167Z,1747681107.167 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T18:58:27.167Z,1747681107.167 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T18:58:29.182Z,1747681109.182 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185828.00,A,3648.03211,N,12150.04598,W,18.739,239.36,190525,,,D*4B 2025-05-19T18:58:29.184Z,1747681109.184 [NAL9602](INFO): GPS fix at 20250519T185828: (36.800535, -121.834100) 2025-05-19T18:58:29.195Z,1747681109.195 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T18:58:29.195Z,1747681109.195 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T18:58:36.957Z,1747681116.957 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250519T143346/Courier0142.lzma 2025-05-19T18:58:37.959Z,1747681117.959 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0142.lzma.bak 2025-05-19T18:58:37.959Z,1747681117.959 [DataOverHttps](INFO): SBD MOMSN=24922239 2025-05-19T18:58:42.504Z,1747681122.504 [NAL9602](INFO): SBD MO Status=0, MOMSN=63172, MT Status=0, MTMSN=0 2025-05-19T18:58:42.504Z,1747681122.504 [NAL9602](INFO): No messages in MT queue 2025-05-19T18:58:56.802Z,1747681136.802 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250519T143346/Express0143.lzma 2025-05-19T18:58:57.803Z,1747681137.803 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0143.lzma.bak 2025-05-19T18:58:57.804Z,1747681137.804 [DataOverHttps](INFO): SBD MOMSN=24922245 2025-05-19T18:58:59.124Z,1747681139.124 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T18:58:59.124Z,1747681139.124 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T18:58:59.124Z,1747681139.124 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T18:59:13.250Z,1747681153.250 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T19:03:59.710Z,1747681439.710 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-05-19T19:03:59.710Z,1747681439.710 [Default:CheckIn:C.Wait] Stopped 2025-05-19T19:03:59.710Z,1747681439.710 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-05-19T19:03:59.710Z,1747681439.710 [Default:CheckIn:D] Running Loop=1 2025-05-19T19:04:00.125Z,1747681440.125 [Default:CheckIn:D] Stopped 2025-05-19T19:04:00.125Z,1747681440.125 [Default:CheckIn:E] Running Loop=1 2025-05-19T19:04:00.516Z,1747681440.516 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 265.953792 min 2025-05-19T19:04:00.516Z,1747681440.516 [Default:CheckIn:E] Stopped 2025-05-19T19:04:00.517Z,1747681440.517 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-05-19T19:04:00.517Z,1747681440.517 [Default:CheckIn] Stopped 2025-05-19T19:04:00.517Z,1747681440.517 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-05-19T19:04:00.517Z,1747681440.517 [Default:CheckIn](INFO): Running loop #46 2025-05-19T19:04:00.517Z,1747681440.517 [Default:CheckIn] Running Loop=46 2025-05-19T19:04:00.517Z,1747681440.517 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-05-19T19:04:00.517Z,1747681440.517 [Default:CheckIn:Read_GPS] Running Loop=1 2025-05-19T19:04:02.526Z,1747681442.526 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190401.00,A,3647.78866,N,12150.66279,W,1.633,83.53,190525,,,D*4E 2025-05-19T19:04:02.528Z,1747681442.528 [NAL9602](INFO): GPS fix at 20250519T190401: (36.796478, -121.844380) 2025-05-19T19:04:02.539Z,1747681442.539 [Default:CheckIn:Read_GPS] Stopped 2025-05-19T19:04:02.539Z,1747681442.539 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-05-19T19:04:10.369Z,1747681450.369 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250519T143346/Courier0145.lzma 2025-05-19T19:04:11.372Z,1747681451.372 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Courier0145.lzma.bak 2025-05-19T19:04:11.372Z,1747681451.372 [DataOverHttps](INFO): SBD MOMSN=24922259 2025-05-19T19:04:18.284Z,1747681458.284 [NAL9602](INFO): SBD MO Status=0, MOMSN=63173, MT Status=0, MTMSN=0 2025-05-19T19:04:18.284Z,1747681458.284 [NAL9602](INFO): No messages in MT queue 2025-05-19T19:04:30.633Z,1747681470.633 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20250519T143346/Express0146.lzma 2025-05-19T19:04:31.635Z,1747681471.635 [DataOverHttps](INFO): Moved sent file to Logs/20250519T143346/Express0146.lzma.bak 2025-05-19T19:04:31.635Z,1747681471.635 [DataOverHttps](INFO): SBD MOMSN=24922267 2025-05-19T19:04:32.894Z,1747681472.894 [Default:CheckIn:Read_Iridium] Stopped 2025-05-19T19:04:32.894Z,1747681472.894 [Default:CheckIn:C.Wait] Running Loop=1 2025-05-19T19:04:32.894Z,1747681472.894 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-05-19T19:04:49.038Z,1747681489.038 [NAL9602](INFO): Not Powering down - fast GPS 2025-05-19T19:05:41.322Z,1747681541.322 [DataOverHttps](IMPORTANT): SBD MTMSN=20250519T190540 2025-05-19T19:05:48.885Z,1747681548.885 [DataOverHttps](INFO): Received command: restart logs