2025-08-05T16:11:13.416Z,1754410273.416 [Supervisor](DEBUG): Initializing supervisor. 2025-08-05T16:11:13.420Z,1754410273.420 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-08-05T16:11:13.420Z,1754410273.420 [SyncHandler](INFO): Protected caller Thread ID is 837 2025-08-05T16:11:13.421Z,1754410273.421 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-08-05T16:11:13.422Z,1754410273.422 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-08-05T16:11:13.422Z,1754410273.422 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838 2025-08-05T16:11:13.426Z,1754410273.426 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-08-05T16:11:13.447Z,1754410273.447 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-08-05T16:11:13.448Z,1754410273.448 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-08-05T16:11:13.448Z,1754410273.448 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839 2025-08-05T16:11:13.452Z,1754410273.452 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-08-05T16:11:13.453Z,1754410273.453 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-08-05T16:11:13.454Z,1754410273.454 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840 2025-08-05T16:11:13.456Z,1754410273.456 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-08-05T16:11:13.457Z,1754410273.457 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-08-05T16:11:13.457Z,1754410273.457 [logger ThreadHandler](INFO): Protected caller Thread ID is 841 2025-08-05T16:11:13.461Z,1754410273.461 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-08-05T16:11:13.462Z,1754410273.462 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-08-05T16:11:13.465Z,1754410273.465 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-08-05T16:11:13.829Z,1754410273.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-08-05T16:11:13.831Z,1754410273.831 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-08-05T16:11:13.934Z,1754410273.934 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-08-05T16:11:13.936Z,1754410273.936 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-08-05T16:11:14.057Z,1754410274.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-08-05T16:11:14.059Z,1754410274.059 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-08-05T16:11:14.220Z,1754410274.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-08-05T16:11:14.221Z,1754410274.221 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-08-05T16:11:14.602Z,1754410274.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-08-05T16:11:14.602Z,1754410274.602 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-08-05T16:11:14.712Z,1754410274.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-08-05T16:11:14.713Z,1754410274.713 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-08-05T16:11:15.148Z,1754410275.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-08-05T16:11:15.148Z,1754410275.148 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-08-05T16:11:15.400Z,1754410275.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-08-05T16:11:15.402Z,1754410275.402 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-08-05T16:11:15.493Z,1754410275.493 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-08-05T16:11:15.758Z,1754410275.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-08-05T16:11:15.760Z,1754410275.760 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-08-05T16:11:16.016Z,1754410276.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-08-05T16:11:16.035Z,1754410276.035 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-08-05T16:11:16.686Z,1754410276.686 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-08-05T16:11:16.687Z,1754410276.687 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-08-05T16:11:16.893Z,1754410276.893 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-08-05T16:11:16.895Z,1754410276.895 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-08-05T16:11:17.206Z,1754410277.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-08-05T16:11:17.207Z,1754410277.207 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-08-05T16:11:18.126Z,1754410278.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-08-05T16:11:18.128Z,1754410278.128 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-08-05T16:11:18.745Z,1754410278.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-08-05T16:11:18.747Z,1754410278.747 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/ 2025-08-05T16:11:18.750Z,1754410278.750 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg 2025-08-05T16:11:18.860Z,1754410278.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg 2025-08-05T16:11:19.008Z,1754410279.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg 2025-08-05T16:11:19.104Z,1754410279.104 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg 2025-08-05T16:11:19.224Z,1754410279.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg 2025-08-05T16:11:19.329Z,1754410279.329 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg 2025-08-05T16:11:19.614Z,1754410279.614 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-08-05T16:11:19.616Z,1754410279.616 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg 2025-08-05T16:11:19.738Z,1754410279.738 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg 2025-08-05T16:11:19.848Z,1754410279.848 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg 2025-08-05T16:11:20.002Z,1754410280.002 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg 2025-08-05T16:11:20.098Z,1754410280.098 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-08-05T16:11:20.111Z,1754410280.111 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-08-05T16:11:20.297Z,1754410280.297 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-08-05T16:11:20.297Z,1754410280.297 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-08-05T16:11:20.375Z,1754410280.375 [VerticalControl](DEBUG): Construct VerticalControl. 2025-08-05T16:11:20.440Z,1754410280.440 [VerticalControl] Loaded 2025-08-05T16:11:20.440Z,1754410280.440 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-08-05T16:11:20.443Z,1754410280.443 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-08-05T16:11:20.493Z,1754410280.493 [HorizontalControl] Loaded 2025-08-05T16:11:20.493Z,1754410280.493 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-08-05T16:11:20.496Z,1754410280.496 [SpeedControl](DEBUG): Construct SpeedControl. 2025-08-05T16:11:20.499Z,1754410280.499 [SpeedControl] Loaded 2025-08-05T16:11:20.499Z,1754410280.499 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-08-05T16:11:20.502Z,1754410280.502 [LoopControl](DEBUG): Construct LoopControl. 2025-08-05T16:11:20.502Z,1754410280.502 [LoopControl] Loaded 2025-08-05T16:11:20.503Z,1754410280.503 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-08-05T16:11:20.503Z,1754410280.503 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-08-05T16:11:20.504Z,1754410280.504 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-08-05T16:11:20.596Z,1754410280.596 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-08-05T16:11:20.597Z,1754410280.597 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-08-05T16:11:21.486Z,1754410281.486 [AHRS_M2] Loaded 2025-08-05T16:11:21.486Z,1754410281.486 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-08-05T16:11:21.750Z,1754410281.750 [BackseatComponent] Loaded 2025-08-05T16:11:21.750Z,1754410281.750 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-08-05T16:11:21.752Z,1754410281.752 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BA4E0 2025-08-05T16:11:21.752Z,1754410281.752 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 920 2025-08-05T16:11:21.755Z,1754410281.755 [LcmUniversalReporter] Loaded 2025-08-05T16:11:21.755Z,1754410281.755 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-08-05T16:11:22.629Z,1754410282.629 [BPC1] Loaded 2025-08-05T16:11:22.630Z,1754410282.630 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-08-05T16:11:22.733Z,1754410282.733 [DAT] Loaded 2025-08-05T16:11:22.733Z,1754410282.733 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-08-05T16:11:22.734Z,1754410282.734 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408EA4E0 2025-08-05T16:11:22.735Z,1754410282.735 [DAT ThreadHandler](INFO): Protected caller Thread ID is 921 2025-08-05T16:11:22.875Z,1754410282.875 [DataOverHttps] Loaded 2025-08-05T16:11:22.875Z,1754410282.875 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-08-05T16:11:22.876Z,1754410282.876 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091A4E0 2025-08-05T16:11:22.877Z,1754410282.877 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 922 2025-08-05T16:11:22.902Z,1754410282.902 [Depth_Keller] Loaded 2025-08-05T16:11:22.902Z,1754410282.902 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-08-05T16:11:22.908Z,1754410282.908 [DropWeight] Loaded 2025-08-05T16:11:22.908Z,1754410282.908 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-08-05T16:11:22.977Z,1754410282.977 [NAL9602] Loaded 2025-08-05T16:11:22.977Z,1754410282.977 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-08-05T16:11:23.009Z,1754410283.009 [Onboard] Loaded 2025-08-05T16:11:23.009Z,1754410283.009 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-08-05T16:11:23.011Z,1754410283.011 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094A4E0 2025-08-05T16:11:23.011Z,1754410283.011 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923 2025-08-05T16:11:23.026Z,1754410283.026 [Power24vConverter] Loaded 2025-08-05T16:11:23.026Z,1754410283.026 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-08-05T16:11:23.043Z,1754410283.043 [Radio_Surface] Loaded 2025-08-05T16:11:23.043Z,1754410283.043 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-08-05T16:11:23.044Z,1754410283.044 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097A4E0 2025-08-05T16:11:23.045Z,1754410283.045 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924 2025-08-05T16:11:23.061Z,1754410283.061 [Sonardyne_Nano] Loaded 2025-08-05T16:11:23.062Z,1754410283.062 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-08-05T16:11:23.087Z,1754410283.087 [Waterlinked] Loaded 2025-08-05T16:11:23.088Z,1754410283.088 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread. 2025-08-05T16:11:23.088Z,1754410283.088 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-08-05T16:11:23.089Z,1754410283.089 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-08-05T16:11:23.105Z,1754410283.105 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-08-05T16:11:23.106Z,1754410283.106 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-08-05T16:11:23.156Z,1754410283.156 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-08-05T16:11:23.156Z,1754410283.156 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-08-05T16:11:23.375Z,1754410283.375 [SBIT](DEBUG): Construct Startup Built In Test. 2025-08-05T16:11:23.384Z,1754410283.384 [SBIT] Loaded 2025-08-05T16:11:23.385Z,1754410283.385 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-08-05T16:11:23.388Z,1754410283.388 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-08-05T16:11:23.401Z,1754410283.401 [IBIT] Loaded 2025-08-05T16:11:23.402Z,1754410283.402 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-08-05T16:11:23.407Z,1754410283.407 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-08-05T16:11:23.492Z,1754410283.492 [CBIT] Loaded 2025-08-05T16:11:23.493Z,1754410283.493 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-08-05T16:11:23.528Z,1754410283.528 [GFScanner] Loaded 2025-08-05T16:11:23.529Z,1754410283.529 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-08-05T16:11:23.529Z,1754410283.529 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-08-05T16:11:23.530Z,1754410283.530 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-08-05T16:11:23.987Z,1754410283.987 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-08-05T16:11:23.988Z,1754410283.988 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-08-05T16:11:24.063Z,1754410284.063 [DepthRateCalculator] Loaded 2025-08-05T16:11:24.063Z,1754410284.063 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-08-05T16:11:24.069Z,1754410284.069 [PitchRateCalculator] Loaded 2025-08-05T16:11:24.069Z,1754410284.069 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-08-05T16:11:24.080Z,1754410284.080 [SpeedCalculator] Loaded 2025-08-05T16:11:24.080Z,1754410284.080 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-08-05T16:11:24.085Z,1754410284.085 [YawRateCalculator] Loaded 2025-08-05T16:11:24.085Z,1754410284.085 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-08-05T16:11:24.106Z,1754410284.106 [ElevatorOffsetCalculator] Loaded 2025-08-05T16:11:24.106Z,1754410284.106 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-08-05T16:11:24.106Z,1754410284.106 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-08-05T16:11:24.107Z,1754410284.107 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-08-05T16:11:24.359Z,1754410284.359 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-08-05T16:11:24.359Z,1754410284.359 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-08-05T16:11:24.508Z,1754410284.508 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-08-05T16:11:24.509Z,1754410284.509 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-08-05T16:11:24.523Z,1754410284.523 [NavChart] Loaded 2025-08-05T16:11:24.524Z,1754410284.524 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-08-05T16:11:24.530Z,1754410284.530 [UniversalFixResidualReporter] Loaded 2025-08-05T16:11:24.530Z,1754410284.530 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-08-05T16:11:24.530Z,1754410284.530 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-08-05T16:11:24.531Z,1754410284.531 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-08-05T16:11:24.712Z,1754410284.712 [BuoyancyServo] Loaded 2025-08-05T16:11:24.713Z,1754410284.713 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-08-05T16:11:24.737Z,1754410284.737 [ElevatorServo] Loaded 2025-08-05T16:11:24.737Z,1754410284.737 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-08-05T16:11:24.761Z,1754410284.761 [MassServo] Loaded 2025-08-05T16:11:24.761Z,1754410284.761 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-08-05T16:11:24.784Z,1754410284.784 [RudderServo] Loaded 2025-08-05T16:11:24.784Z,1754410284.784 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-08-05T16:11:24.802Z,1754410284.802 [ThrusterHE] Loaded 2025-08-05T16:11:24.802Z,1754410284.802 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-08-05T16:11:24.803Z,1754410284.803 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-08-05T16:11:24.803Z,1754410284.803 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-08-05T16:11:25.046Z,1754410285.046 [CTD_Seabird] Loaded 2025-08-05T16:11:25.046Z,1754410285.046 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-08-05T16:11:25.047Z,1754410285.047 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C094E0 2025-08-05T16:11:25.047Z,1754410285.047 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 925 2025-08-05T16:11:25.087Z,1754410285.087 [ESPComponent] Loaded 2025-08-05T16:11:25.087Z,1754410285.087 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-08-05T16:11:25.111Z,1754410285.111 [PAR_Licor] Loaded 2025-08-05T16:11:25.112Z,1754410285.112 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-08-05T16:11:25.160Z,1754410285.160 [WetLabsBB2FL] Loaded 2025-08-05T16:11:25.160Z,1754410285.160 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-08-05T16:11:25.161Z,1754410285.161 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C394E0 2025-08-05T16:11:25.162Z,1754410285.162 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 926 2025-08-05T16:11:25.163Z,1754410285.163 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-08-05T16:11:25.169Z,1754410285.169 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-08-05T16:11:25.172Z,1754410285.172 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-08-05T16:11:25.184Z,1754410285.184 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-08-05T16:11:25.185Z,1754410285.185 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C694E0 2025-08-05T16:11:25.185Z,1754410285.185 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 927 2025-08-05T16:11:25.190Z,1754410285.190 [Supervisor](INFO): Main Thread ID is 828 2025-08-05T16:11:25.190Z,1754410285.190 [Supervisor](DEBUG): Running supervisor. 2025-08-05T16:11:25.191Z,1754410285.191 [CommandExec ThreadHandler](INFO): Handler Thread ID is 928 2025-08-05T16:11:25.191Z,1754410285.191 [CommandExec](INFO): Initializing the command executive. 2025-08-05T16:11:25.193Z,1754410285.193 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929 2025-08-05T16:11:25.195Z,1754410285.195 [controlThread ThreadHandler](INFO): Handler Thread ID is 930 2025-08-05T16:11:25.195Z,1754410285.195 [controlThread](DEBUG): Initializing ControlThread 2025-08-05T16:11:25.196Z,1754410285.196 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-08-05T16:11:25.198Z,1754410285.198 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-08-05T16:11:25.198Z,1754410285.198 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-08-05T16:11:25.199Z,1754410285.199 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-08-05T16:11:25.202Z,1754410285.202 [SBIT](INFO): Initialize SBIT Component. 2025-08-05T16:11:25.202Z,1754410285.202 [SBIT](IMPORTANT): git: 2025-07-17-7-g184199333 2025-08-05T16:11:25.202Z,1754410285.202 [SBIT](INFO): git hash: 1841993335de4f098fcec04cd714926e036c3b35 2025-08-05T16:11:25.203Z,1754410285.203 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-08-05T16:11:25.204Z,1754410285.204 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #1 PREEMPT Tue Nov 28 15:04:22 PST 2023 2025-08-05T16:11:25.205Z,1754410285.205 [SBIT](INFO): Beginning SBIT in 117.000000 seconds. 2025-08-05T16:11:25.206Z,1754410285.206 [IBIT](INFO): Initialize IBIT Component. 2025-08-05T16:11:25.206Z,1754410285.206 [CBIT](DEBUG): Initialize CBIT Component. 2025-08-05T16:11:25.207Z,1754410285.207 [logger ThreadHandler](INFO): Handler Thread ID is 931 2025-08-05T16:11:25.217Z,1754410285.217 [CBIT](DEBUG): Initialized mux pins. 2025-08-05T16:11:25.217Z,1754410285.217 [CBIT](DEBUG): Initializing the watchdog timer. 2025-08-05T16:11:25.225Z,1754410285.225 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 932 2025-08-05T16:11:25.241Z,1754410285.241 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-08-05T16:11:25.241Z,1754410285.241 [CBIT](DEBUG): Initializing heartbeat. 2025-08-05T16:11:25.242Z,1754410285.242 [DAT ThreadHandler](INFO): Handler Thread ID is 933 2025-08-05T16:11:25.243Z,1754410285.243 [DAT](INFO): Powering up 2025-08-05T16:11:25.243Z,1754410285.243 [DAT](DEBUG): Initializing DAT. 2025-08-05T16:11:25.246Z,1754410285.246 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 935 2025-08-05T16:11:25.248Z,1754410285.248 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-08-05T16:11:25.269Z,1754410285.269 [Onboard ThreadHandler](INFO): Handler Thread ID is 936 2025-08-05T16:11:25.287Z,1754410285.287 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 937 2025-08-05T16:11:25.305Z,1754410285.305 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 938 2025-08-05T16:11:25.306Z,1754410285.306 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-08-05T16:11:25.310Z,1754410285.310 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 940 2025-08-05T16:11:25.313Z,1754410285.313 [CBIT](DEBUG): Deactivating emergency mode. 2025-08-05T16:11:25.314Z,1754410285.314 [WetLabsBB2FL](INFO): Powering up 2025-08-05T16:11:25.315Z,1754410285.315 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 942 2025-08-05T16:11:25.322Z,1754410285.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-08-05T16:11:25.322Z,1754410285.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-08-05T16:11:25.322Z,1754410285.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-08-05T16:11:25.322Z,1754410285.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-08-05T16:11:25.322Z,1754410285.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-08-05T16:11:25.322Z,1754410285.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-08-05T16:11:25.323Z,1754410285.323 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-08-05T16:11:25.323Z,1754410285.323 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-08-05T16:11:25.353Z,1754410285.353 [CBIT](DEBUG): Backplane powered. 2025-08-05T16:11:25.353Z,1754410285.353 [GFScanner](DEBUG): Initializing GFScanner 2025-08-05T16:11:25.353Z,1754410285.353 [GFScanner](DEBUG): Deactivating GF circuits. 2025-08-05T16:11:25.358Z,1754410285.358 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-08-05T16:11:25.358Z,1754410285.358 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-08-05T16:11:25.358Z,1754410285.358 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-08-05T16:11:25.359Z,1754410285.359 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-08-05T16:11:25.359Z,1754410285.359 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-08-05T16:11:25.360Z,1754410285.360 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-08-05T16:11:25.361Z,1754410285.361 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-08-05T16:11:25.374Z,1754410285.374 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-08-05T16:11:25.374Z,1754410285.374 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-08-05T16:11:25.375Z,1754410285.375 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-08-05T16:11:25.379Z,1754410285.379 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-08-05T16:11:25.453Z,1754410285.453 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-08-05T16:11:25.465Z,1754410285.465 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-08-05T16:11:25.517Z,1754410285.517 [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-08-05T16:11:25.530Z,1754410285.530 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-08-05T16:11:25.530Z,1754410285.530 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-08-05T16:11:25.543Z,1754410285.543 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-08-05T16:11:25.693Z,1754410285.693 [Radio_Surface](INFO): Powering up 2025-08-05T16:11:25.864Z,1754410285.864 [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-08-05T16:11:25.878Z,1754410285.878 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-08-05T16:11:25.879Z,1754410285.879 [Default:A.Wait](DEBUG): Construct Wait. 2025-08-05T16:11:25.893Z,1754410285.893 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-08-05T16:11:25.930Z,1754410285.930 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-08-05T16:11:25.933Z,1754410285.933 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-08-05T16:11:25.955Z,1754410285.955 [Default:E.Execute](DEBUG): Construct Execute. 2025-08-05T16:11:25.958Z,1754410285.958 [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-08-05T16:11:25.977Z,1754410285.977 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,Waterlinked,ESPComponent,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,LcmUniversalReporter,Reporter,LogSplitter, 2025-08-05T16:11:25.989Z,1754410285.989 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-08-05T16:11:26.126Z,1754410286.126 [Depth_Keller](INFO): Initializing. 2025-08-05T16:11:26.127Z,1754410286.127 [Power24vConverter](INFO): Powering up. 2025-08-05T16:11:26.128Z,1754410286.128 [Sonardyne_Nano](INFO): Initializing. 2025-08-05T16:11:26.170Z,1754410286.170 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-08-05T16:11:26.196Z,1754410286.196 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-08-05T16:11:26.201Z,1754410286.201 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-08-05T16:11:26.202Z,1754410286.202 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-08-05T16:11:26.209Z,1754410286.209 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-08-05T16:11:26.210Z,1754410286.210 [MassServo](DEBUG): Initializing EZServoServo. 2025-08-05T16:11:26.217Z,1754410286.217 [MassServo](DEBUG): Initializing MassServo. 2025-08-05T16:11:26.218Z,1754410286.218 [RudderServo](DEBUG): Initializing EZServoServo. 2025-08-05T16:11:26.225Z,1754410286.225 [RudderServo](DEBUG): Initializing RudderServo. 2025-08-05T16:11:26.226Z,1754410286.226 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-08-05T16:11:26.233Z,1754410286.233 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-08-05T16:11:27.421Z,1754410287.421 [WetLabsBB2FL](INFO): Powering down 2025-08-05T16:11:28.412Z,1754410288.412 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-08-05T16:11:29.666Z,1754410289.666 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311 2025-08-05T16:11:31.934Z,1754410291.934 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-08-05T16:11:32.342Z,1754410292.342 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2025-08-05T16:11:38.618Z,1754410298.618 [DAT](INFO): DAT read: 2025-08-05T16:11:38.619Z,1754410298.619 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-08-05T16:11:40.382Z,1754410300.382 [DAT](INFO): DAT read: MF Frequency Band 2025-08-05T16:11:40.383Z,1754410300.383 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-08-05T16:11:40.384Z,1754410300.384 [DAT](INFO): DAT read: Aug 4 2025 23:26:44 2025-08-05T16:11:41.642Z,1754410301.642 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-08-05T16:11:41.643Z,1754410301.643 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-08-05T16:11:41.644Z,1754410301.644 [DAT](INFO): commRate: 800 2025-08-05T16:11:43.709Z,1754410303.709 [DAT](INFO): entering command mode 2025-08-05T16:11:43.910Z,1754410303.910 [DAT](INFO): DAT read: 2025-08-05T16:11:43.910Z,1754410303.910 [DAT](INFO): DAT read: user:1> 2025-08-05T16:11:43.911Z,1754410303.911 [DAT](INFO): setting verbose to 3 2025-08-05T16:11:44.162Z,1754410304.162 [DAT](INFO): DAT read: user:1> 2025-08-05T16:11:44.163Z,1754410304.163 [DAT](INFO): DAT read: Verbose | 3 2025-08-05T16:11:44.163Z,1754410304.163 [DAT](INFO): set verbose to 3 2025-08-05T16:11:44.164Z,1754410304.164 [DAT](INFO): setting DatVerbose to 27440 2025-08-05T16:11:44.414Z,1754410304.414 [DAT](INFO): DAT read: user:2> 2025-08-05T16:11:44.415Z,1754410304.415 [DAT](INFO): DAT read: DatVerbose | 27440 2025-08-05T16:11:44.415Z,1754410304.415 [DAT](INFO): set DatVerbose to 27440 2025-08-05T16:11:44.415Z,1754410304.415 [DAT](INFO): setting transmit power to 8 2025-08-05T16:11:44.666Z,1754410304.666 [DAT](INFO): DAT read: user:3> 2025-08-05T16:11:44.667Z,1754410304.667 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-08-05T16:11:44.667Z,1754410304.667 [DAT](INFO): set transmit power to 8 2025-08-05T16:11:44.668Z,1754410304.668 [DAT](INFO): setting local address to 1 2025-08-05T16:11:44.918Z,1754410304.918 [DAT](INFO): DAT read: user:4> 2025-08-05T16:11:44.919Z,1754410304.919 [DAT](INFO): DAT read: LocalAddr | 1 2025-08-05T16:11:44.919Z,1754410304.919 [DAT](INFO): set local address to 1 2025-08-05T16:11:44.920Z,1754410304.920 [DAT](INFO): Setting time to: 16:11:44 And date to:8/5/2025 2025-08-05T16:11:45.170Z,1754410305.170 [DAT](INFO): DAT read: user:5> 2025-08-05T16:11:45.170Z,1754410305.170 [DAT](INFO): DAT read: Tue Aug 5, 2025 16:11:44 2025-08-05T16:11:45.171Z,1754410305.171 [DAT](INFO): Local DAT time set to Tue Aug 5, 2025 16:11:44 2025-08-05T16:11:53.099Z,1754410313.099 [NAL9602](INFO): Powering up NAL9602 2025-08-05T16:12:03.469Z,1754410323.469 [Waterlinked](INFO): Powering down 2025-08-05T16:12:04.176Z,1754410324.176 [NAL9602](INFO): NAL9602 initialized 2025-08-05T16:12:33.255Z,1754410353.255 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:12:49.013Z,1754410369.013 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:13:05.586Z,1754410385.586 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:13:18.858Z,1754410398.858 [CommandExec](IMPORTANT): got command strobe off 2025-08-05T16:13:18.859Z,1754410398.859 [CommandExec](IMPORTANT): Deactivating strobe 2025-08-05T16:13:22.141Z,1754410402.141 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:13:22.994Z,1754410402.994 [SBIT](IMPORTANT): Beginning Startup BIT 2025-08-05T16:13:22.999Z,1754410402.999 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-08-05T16:13:27.482Z,1754410407.482 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.000045 CHAN A1 (24V): 0.001309 CHAN A2 (12V): 0.000471 CHAN A3 (5V): -0.001401 CHAN B0 (3.3V): 0.000403 CHAN B1 (3.15aV): -0.000125 CHAN B2 (3.15bV): -0.000128 CHAN B3 (GND): -0.000436 OPEN: 0.006582 Full Scale: +/- 1 mA 2025-08-05T16:13:34.495Z,1754410414.495 [CommandExec](IMPORTANT): got command burn on 2025-08-05T16:13:34.495Z,1754410414.495 [CommandExec](IMPORTANT): Activating dropweight wire 2025-08-05T16:13:38.299Z,1754410418.299 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:13:38.962Z,1754410418.962 [CommandExec](IMPORTANT): got command burn off 2025-08-05T16:13:38.962Z,1754410418.962 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-08-05T16:13:45.007Z,1754410425.007 [CommandExec](IMPORTANT): got command burn on 2025-08-05T16:13:45.007Z,1754410425.007 [CommandExec](IMPORTANT): Activating dropweight wire 2025-08-05T16:13:47.926Z,1754410427.926 [CommandExec](IMPORTANT): got command burn off 2025-08-05T16:13:47.926Z,1754410427.926 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-08-05T16:13:54.459Z,1754410434.459 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:13:59.240Z,1754410439.240 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005130 2025-08-05T16:14:11.379Z,1754410451.379 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:14:16.676Z,1754410456.676 [SBIT](IMPORTANT): SBIT PASSED 2025-08-05T16:14:16.676Z,1754410456.676 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-08-05T16:14:16.677Z,1754410456.677 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=15 count; 2025-08-05T16:14:16.677Z,1754410456.677 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter; 2025-08-05T16:14:16.677Z,1754410456.677 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 2.000000 count_per_second; 2025-08-05T16:14:16.677Z,1754410456.677 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 100.000000 count_per_second; 2025-08-05T16:14:16.677Z,1754410456.677 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=203.823169 cubic_centimeter; 2025-08-05T16:14:16.678Z,1754410456.678 [SBIT](IMPORTANT): VerticalControl.massDefault=24.289926 millimeter; 2025-08-05T16:14:17.071Z,1754410457.071 [MissionManager](IMPORTANT): Started mission Startup 2025-08-05T16:14:17.071Z,1754410457.071 [Startup] Running Loop=1 2025-08-05T16:14:17.071Z,1754410457.071 [Startup](DEBUG): Aggregate::initialize Startup 2025-08-05T16:14:17.071Z,1754410457.071 [Startup:A.GoToSurface] Running Loop=1 2025-08-05T16:14:17.071Z,1754410457.071 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-05T16:14:17.072Z,1754410457.072 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-05T16:14:17.072Z,1754410457.072 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-05T16:14:17.093Z,1754410457.093 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-05T16:14:17.093Z,1754410457.093 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-05T16:14:17.094Z,1754410457.094 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-05T16:14:17.094Z,1754410457.094 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-05T16:14:17.096Z,1754410457.096 [Startup:StartupSatComms] Running Loop=1 2025-08-05T16:14:17.096Z,1754410457.096 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-08-05T16:14:17.096Z,1754410457.096 [Startup:StartupSatComms:A] Running Loop=1 2025-08-05T16:14:17.461Z,1754410457.461 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-08-05T16:14:25.545Z,1754410465.545 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-08-05T16:14:25.545Z,1754410465.545 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-08-05T16:14:25.588Z,1754410465.588 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-08-05T16:14:25.958Z,1754410465.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-08-05T16:14:25.958Z,1754410465.958 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-08-05T16:14:28.347Z,1754410468.347 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:14:43.310Z,1754410483.310 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:14:44.911Z,1754410484.911 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:14:54.273Z,1754410494.273 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:15:05.182Z,1754410505.182 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:15:15.686Z,1754410515.686 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:15:17.247Z,1754410517.247 [Startup:StartupSatComms:A](INFO): Timed out from 2025-08-05T16:14:17.1Z 2025-08-05T16:15:17.247Z,1754410517.247 [Startup:StartupSatComms:A] Stopped 2025-08-05T16:15:17.247Z,1754410517.247 [Startup:StartupSatComms:B] Running Loop=1 2025-08-05T16:15:17.647Z,1754410517.647 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-08-05T16:15:24.242Z,1754410524.242 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250805T161113/Courier0000.lzma 2025-08-05T16:15:25.243Z,1754410525.243 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0000.lzma.bak 2025-08-05T16:15:25.243Z,1754410525.243 [DataOverHttps](INFO): SBD MOMSN=25781767 2025-08-05T16:15:26.595Z,1754410526.595 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:15:37.955Z,1754410537.955 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:15:41.027Z,1754410541.027 [DataOverHttps](INFO): Sending 1004 bytes from file Logs/20250805T161113/Express0001.lzma 2025-08-05T16:15:42.027Z,1754410542.027 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0001.lzma.bak 2025-08-05T16:15:42.027Z,1754410542.027 [DataOverHttps](INFO): SBD MOMSN=25781770 2025-08-05T16:15:43.107Z,1754410543.107 [Startup:StartupSatComms:B] Stopped 2025-08-05T16:15:43.107Z,1754410543.107 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-08-05T16:15:43.107Z,1754410543.107 [Startup:StartupSatComms] Stopped 2025-08-05T16:15:43.107Z,1754410543.107 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-08-05T16:15:43.108Z,1754410543.108 [Startup](INFO): Completed Startup 2025-08-05T16:15:43.108Z,1754410543.108 [MissionManager](INFO): Startup is completed. 2025-08-05T16:15:43.109Z,1754410543.109 [MissionManager](INFO): Uninitializing Mission Startup 2025-08-05T16:15:43.109Z,1754410543.109 [Startup] Stopped 2025-08-05T16:15:43.109Z,1754410543.109 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-08-05T16:15:43.109Z,1754410543.109 [Startup:A.GoToSurface] Stopped 2025-08-05T16:15:43.109Z,1754410543.109 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-05T16:15:43.512Z,1754410543.512 [MissionManager](IMPORTANT): Started mission Default 2025-08-05T16:15:43.512Z,1754410543.512 [Default] Running Loop=1 2025-08-05T16:15:43.512Z,1754410543.512 [Default](DEBUG): Aggregate::initialize Default 2025-08-05T16:15:43.512Z,1754410543.512 [Default:B.GoToSurface] Running Loop=1 2025-08-05T16:15:43.513Z,1754410543.513 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-05T16:15:43.513Z,1754410543.513 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-05T16:15:43.513Z,1754410543.513 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-05T16:15:43.514Z,1754410543.514 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-05T16:15:43.514Z,1754410543.514 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-05T16:15:43.514Z,1754410543.514 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-05T16:15:43.515Z,1754410543.515 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-05T16:15:43.515Z,1754410543.515 [Default:A.Wait] Running Loop=1 2025-08-05T16:15:43.515Z,1754410543.515 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-08-05T16:15:48.819Z,1754410548.819 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:15:56.863Z,1754410556.863 [Default:A.Wait](INFO): Done Waiting. 2025-08-05T16:15:56.863Z,1754410556.863 [Default:A.Wait] Stopped 2025-08-05T16:15:56.863Z,1754410556.863 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T16:15:57.245Z,1754410557.245 [Default:CheckIn] Running Loop=1 2025-08-05T16:15:57.245Z,1754410557.245 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T16:15:57.245Z,1754410557.245 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T16:15:57.648Z,1754410557.648 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-05T16:15:59.725Z,1754410559.725 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:16:10.633Z,1754410570.633 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:16:11.831Z,1754410571.831 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-08-05T16:16:21.596Z,1754410581.596 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:16:23.598Z,1754410583.598 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-08-05T16:16:24.618Z,1754410584.618 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent 2025-08-05T16:16:24.618Z,1754410584.618 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 77.000000 % 2025-08-05T16:16:32.466Z,1754410592.466 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:16:43.778Z,1754410603.778 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:16:53.813Z,1754410613.813 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2025-08-05T16:16:53.815Z,1754410613.815 [BPC1](ERROR): BPC1A failed to parse battery stick message. 2025-08-05T16:17:04.786Z,1754410624.786 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-08-05T16:17:06.743Z,1754410626.743 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-05T16:17:15.620Z,1754410635.620 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:17:26.571Z,1754410646.571 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-08-05T16:17:26.571Z,1754410646.571 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-08-05T16:17:26.582Z,1754410646.582 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-08-05T16:17:26.956Z,1754410646.956 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-08-05T16:17:26.956Z,1754410646.956 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-08-05T16:17:30.568Z,1754410650.568 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:17:45.919Z,1754410665.919 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:18:00.867Z,1754410680.867 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:18:15.815Z,1754410695.815 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:18:30.777Z,1754410710.777 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:18:45.711Z,1754410725.711 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:18:59.891Z,1754410739.891 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:19:14.839Z,1754410754.839 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:19:29.020Z,1754410769.020 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-08-05T16:20:27.570Z,1754410827.570 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-08-05T16:20:27.570Z,1754410827.570 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-08-05T16:20:27.604Z,1754410827.604 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-08-05T16:20:27.988Z,1754410827.988 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-08-05T16:20:27.988Z,1754410827.988 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-08-05T16:20:57.613Z,1754410857.613 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-08-05T16:15:57.2Z 2025-08-05T16:20:57.613Z,1754410857.613 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T16:20:57.613Z,1754410857.613 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T16:20:57.964Z,1754410857.964 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-08-05T16:20:58.882Z,1754410858.882 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250805T161113/Courier0004.lzma 2025-08-05T16:21:09.911Z,1754410869.911 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0004.lzma.bak 2025-08-05T16:21:09.911Z,1754410869.911 [DataOverHttps](INFO): SBD MOMSN=25781827 2025-08-05T16:21:38.681Z,1754410898.681 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20250805T161113/Express0005.lzma 2025-08-05T16:21:49.723Z,1754410909.723 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0005.lzma.bak 2025-08-05T16:21:49.723Z,1754410909.723 [DataOverHttps](INFO): SBD MOMSN=25781829 2025-08-05T16:21:50.928Z,1754410910.928 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T16:21:50.928Z,1754410910.928 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T16:21:50.928Z,1754410910.928 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T16:21:55.735Z,1754410915.735 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:22:07.050Z,1754410927.050 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-08-05T16:22:07.051Z,1754410927.051 [NAL9602] Data Fault, FailCount= 1 2025-08-05T16:22:07.051Z,1754410927.051 [NAL9602](ERROR): Data Fault 2025-08-05T16:22:07.121Z,1754410927.121 [CBIT](ERROR): Data Fault in component: NAL9602 2025-08-05T16:22:07.453Z,1754410927.453 [NAL9602](INFO): Powering down 2025-08-05T16:22:08.304Z,1754410928.304 [CBIT](INFO): Clearing failed state for component NAL9602 2025-08-05T16:22:08.305Z,1754410928.305 [NAL9602] No Fault, FailCount= 1 2025-08-05T16:22:09.875Z,1754410929.875 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:22:23.611Z,1754410943.611 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:22:37.756Z,1754410957.756 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:22:37.764Z,1754410957.764 [NAL9602](INFO): Powering up NAL9602 2025-08-05T16:22:48.707Z,1754410968.707 [NAL9602](INFO): NAL9602 initialized 2025-08-05T16:22:51.523Z,1754410971.523 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:23:05.727Z,1754410985.727 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:23:19.867Z,1754410999.867 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:23:28.816Z,1754411008.816 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-08-05T16:23:28.816Z,1754411008.816 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-08-05T16:23:28.874Z,1754411008.874 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-08-05T16:23:29.239Z,1754411009.239 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-08-05T16:23:29.239Z,1754411009.239 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-08-05T16:23:33.199Z,1754411013.199 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:23:46.935Z,1754411026.935 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:24:00.683Z,1754411040.683 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:24:14.017Z,1754411054.017 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T16:24:37.054Z,1754411077.054 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-05T16:24:37.055Z,1754411077.055 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-08-05T16:24:37.055Z,1754411077.055 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-05T16:24:37.056Z,1754411077.056 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-05T16:24:37.057Z,1754411077.057 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2025-08-05T16:24:37.058Z,1754411077.058 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 4. 2025-08-05T16:24:37.061Z,1754411077.061 [BPC1](INFO): Received data from all battery sticks. 2025-08-05T16:26:29.913Z,1754411189.913 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-08-05T16:26:29.913Z,1754411189.913 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-08-05T16:26:29.962Z,1754411189.962 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-08-05T16:26:30.345Z,1754411190.345 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-08-05T16:26:30.345Z,1754411190.345 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-08-05T16:26:51.314Z,1754411211.314 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T16:26:51.314Z,1754411211.314 [Default:CheckIn:C.Wait] Stopped 2025-08-05T16:26:51.314Z,1754411211.314 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T16:26:51.314Z,1754411211.314 [Default:CheckIn:D] Running Loop=1 2025-08-05T16:26:51.714Z,1754411211.714 [Default:CheckIn:D] Stopped 2025-08-05T16:26:51.714Z,1754411211.714 [Default:CheckIn:E] Running Loop=1 2025-08-05T16:26:52.124Z,1754411212.124 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.136693 min 2025-08-05T16:26:52.124Z,1754411212.124 [Default:CheckIn:E] Stopped 2025-08-05T16:26:52.124Z,1754411212.124 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T16:26:52.124Z,1754411212.124 [Default:CheckIn] Stopped 2025-08-05T16:26:52.124Z,1754411212.124 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T16:26:52.124Z,1754411212.124 [Default:CheckIn](INFO): Running loop #2 2025-08-05T16:26:52.124Z,1754411212.124 [Default:CheckIn] Running Loop=2 2025-08-05T16:26:52.165Z,1754411212.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T16:26:52.165Z,1754411212.165 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T16:29:30.929Z,1754411370.929 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-08-05T16:29:30.929Z,1754411370.929 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-08-05T16:29:30.964Z,1754411370.964 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-08-05T16:29:31.371Z,1754411371.371 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-08-05T16:29:31.371Z,1754411371.371 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-08-05T16:30:10.916Z,1754411410.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163009.00,A,3648.17137,N,12147.28291,W,0.292,347.52,050825,,,A*7E 2025-08-05T16:30:10.919Z,1754411410.919 [NAL9602](INFO): GPS fix at 20250805T163009: (36.802856, -121.788049) 2025-08-05T16:30:10.971Z,1754411410.971 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T16:30:10.971Z,1754411410.971 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T16:30:29.489Z,1754411429.489 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20250805T161113/Courier0007.lzma 2025-08-05T16:30:43.293Z,1754411443.293 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T16:30:45.587Z,1754411445.587 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0007.lzma.bak 2025-08-05T16:30:45.587Z,1754411445.587 [DataOverHttps](INFO): SBD MOMSN=25781835 2025-08-05T16:31:25.405Z,1754411485.405 [DataOverHttps](INFO): Sending 406 bytes from file Logs/20250805T161113/Express0008.lzma 2025-08-05T16:31:36.447Z,1754411496.447 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0008.lzma.bak 2025-08-05T16:31:36.447Z,1754411496.447 [DataOverHttps](IMPORTANT): SBD MOMSN=25781839, MTMSN=20250805T163135 2025-08-05T16:31:37.632Z,1754411497.632 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T16:31:37.632Z,1754411497.632 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T16:31:37.632Z,1754411497.632 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T16:31:46.557Z,1754411506.557 [DataOverHttps](INFO): Received command: failc 2025-08-05T16:31:46.622Z,1754411506.622 [CommandExec](IMPORTANT): got command failComponent 2025-08-05T16:31:46.623Z,1754411506.623 [CommandExec](IMPORTANT): Failed components: 2025-08-05T16:31:46.623Z,1754411506.623 [CommandExec](IMPORTANT): No failed Components. 2025-08-05T16:31:57.604Z,1754411517.604 [DataOverHttps](IMPORTANT): SBD MTMSN=20250805T163156 2025-08-05T16:32:07.641Z,1754411527.641 [DataOverHttps](INFO): Received command: sched 20250805T1635 "ibit" 2025-08-05T16:32:07.664Z,1754411527.664 [CommandExec](IMPORTANT): got command schedule 20250805T163500 "ibit" 2025-08-05T16:32:07.666Z,1754411527.666 [CommandExec](IMPORTANT): Scheduled #1: "ibit", AT TIME: 2025-08-05T16:35:00Z 2025-08-05T16:35:00.006Z,1754411700.006 [CommandExec](IMPORTANT): got command ibit 2025-08-05T16:35:00.216Z,1754411700.216 [IBIT](IMPORTANT): Beginning Initiated BIT 2025-08-05T16:35:00.216Z,1754411700.216 [IBIT](IMPORTANT): Beginning control surface checks. 2025-08-05T16:35:00.224Z,1754411700.224 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-08-05T16:35:01.779Z,1754411701.779 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163501.00,A,3648.14996,N,12147.22828,W,0.136,4.97,050825,,,D*74 2025-08-05T16:35:01.789Z,1754411701.789 [NAL9602](INFO): GPS fix at 20250805T163501: (36.802499, -121.787138) 2025-08-05T16:35:04.825Z,1754411704.825 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.000669 CHAN A1 (24V): 0.000859 CHAN A2 (12V): 0.000266 CHAN A3 (5V): -0.001550 CHAN B0 (3.3V): -0.000274 CHAN B1 (3.15aV): 0.000328 CHAN B2 (3.15bV): 0.000525 CHAN B3 (GND): -0.000179 OPEN: 0.006088 Full Scale: +/- 1 mA 2025-08-05T16:35:15.925Z,1754411715.925 [NAL9602](INFO): SBD MO Status=0, MOMSN=26322, MT Status=0, MTMSN=0 2025-08-05T16:35:15.925Z,1754411715.925 [NAL9602](INFO): No messages in MT queue 2025-08-05T16:35:17.140Z,1754411717.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163516.00,A,3648.14936,N,12147.22771,W,0.058,4.97,050825,,,D*72 2025-08-05T16:35:17.142Z,1754411717.142 [NAL9602](INFO): GPS fix at 20250805T163516: (36.802489, -121.787128) 2025-08-05T16:35:19.964Z,1754411719.964 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163519.00,A,3648.14925,N,12147.22761,W,0.078,4.97,050825,,,D*7C 2025-08-05T16:35:19.966Z,1754411719.966 [NAL9602](INFO): GPS fix at 20250805T163519: (36.802487, -121.787127) 2025-08-05T16:35:23.196Z,1754411723.196 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163522.00,A,3648.14924,N,12147.22758,W,0.097,4.97,050825,,,D*7E 2025-08-05T16:35:23.199Z,1754411723.199 [NAL9602](INFO): GPS fix at 20250805T163522: (36.802487, -121.787126) 2025-08-05T16:35:26.032Z,1754411726.032 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163525.00,A,3648.14920,N,12147.22753,W,0.117,4.97,050825,,,D*7F 2025-08-05T16:35:26.034Z,1754411726.034 [NAL9602](INFO): GPS fix at 20250805T163525: (36.802487, -121.787126) 2025-08-05T16:35:28.860Z,1754411728.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163528.00,A,3648.14915,N,12147.22727,W,0.039,4.97,050825,,,D*7A 2025-08-05T16:35:28.862Z,1754411728.862 [NAL9602](INFO): GPS fix at 20250805T163528: (36.802486, -121.787121) 2025-08-05T16:35:32.084Z,1754411732.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163531.00,A,3648.14926,N,12147.22727,W,0.330,4.97,050825,,,D*78 2025-08-05T16:35:32.086Z,1754411732.086 [NAL9602](INFO): GPS fix at 20250805T163531: (36.802488, -121.787121) 2025-08-05T16:35:34.912Z,1754411734.912 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163534.00,A,3648.14931,N,12147.22722,W,0.058,4.97,050825,,,D*73 2025-08-05T16:35:34.923Z,1754411734.923 [NAL9602](INFO): GPS fix at 20250805T163534: (36.802489, -121.787120) 2025-08-05T16:35:38.154Z,1754411738.154 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163537.00,A,3648.14932,N,12147.22713,W,0.058,4.97,050825,,,D*71 2025-08-05T16:35:38.156Z,1754411738.156 [NAL9602](INFO): GPS fix at 20250805T163537: (36.802489, -121.787119) 2025-08-05T16:35:40.974Z,1754411740.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163540.00,A,3648.14933,N,12147.22709,W,0.058,4.97,050825,,,D*7B 2025-08-05T16:35:40.976Z,1754411740.976 [NAL9602](INFO): GPS fix at 20250805T163540: (36.802489, -121.787118) 2025-08-05T16:35:43.804Z,1754411743.804 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163543.00,A,3648.14938,N,12147.22701,W,0.058,4.97,050825,,,D*7B 2025-08-05T16:35:43.806Z,1754411743.806 [NAL9602](INFO): GPS fix at 20250805T163543: (36.802490, -121.787117) 2025-08-05T16:35:46.248Z,1754411746.248 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802490 Longitude: -121.787117 2025-08-05T16:35:46.671Z,1754411746.671 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.690001 2025-08-05T16:35:46.671Z,1754411746.671 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2025-08-05T16:35:46.672Z,1754411746.672 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2025-08-05T16:35:47.035Z,1754411747.035 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163546.00,A,3648.14935,N,12147.22691,W,0.058,4.97,050825,,,D*7B 2025-08-05T16:35:47.038Z,1754411747.038 [NAL9602](INFO): GPS fix at 20250805T163546: (36.802489, -121.787115) 2025-08-05T16:35:47.055Z,1754411747.055 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2025-08-05T16:35:47.055Z,1754411747.055 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2025-08-05T16:35:47.055Z,1754411747.055 [IBIT](IMPORTANT): Pressure:10.145852 PSI 2025-08-05T16:35:47.055Z,1754411747.055 [IBIT](IMPORTANT): Humidity:24.197290 % 2025-08-05T16:35:47.475Z,1754411747.475 [IBIT](IMPORTANT): Vehicle Pitch:-1.671490 degrees 2025-08-05T16:35:47.475Z,1754411747.475 [IBIT](IMPORTANT): Vehicle Roll:4.637985 degrees 2025-08-05T16:35:47.475Z,1754411747.475 [IBIT](IMPORTANT): Vehicle Heading:21.473988 degrees 2025-08-05T16:35:47.868Z,1754411747.868 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2025-08-05T16:35:47.868Z,1754411747.868 [IBIT](IMPORTANT): buoyancyNeutral: 203.823166 cc 2025-08-05T16:35:47.868Z,1754411747.868 [IBIT](IMPORTANT): massDefault: 2.428993 cm 2025-08-05T16:35:47.869Z,1754411747.869 [IBIT](IMPORTANT): stopDepth: 290.000000 m 2025-08-05T16:35:47.869Z,1754411747.869 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2025-08-05T16:35:47.869Z,1754411747.869 [IBIT](IMPORTANT): IBIT PASSED 2025-08-05T16:36:19.362Z,1754411779.362 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T16:36:38.359Z,1754411798.359 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T16:36:38.359Z,1754411798.359 [Default:CheckIn:C.Wait] Stopped 2025-08-05T16:36:38.359Z,1754411798.359 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T16:36:38.359Z,1754411798.359 [Default:CheckIn:D] Running Loop=1 2025-08-05T16:36:38.756Z,1754411798.756 [Default:CheckIn:D] Stopped 2025-08-05T16:36:38.756Z,1754411798.756 [Default:CheckIn:E] Running Loop=1 2025-08-05T16:36:39.157Z,1754411799.157 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.920736 min 2025-08-05T16:36:39.157Z,1754411799.157 [Default:CheckIn:E] Stopped 2025-08-05T16:36:39.157Z,1754411799.157 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T16:36:39.157Z,1754411799.157 [Default:CheckIn] Stopped 2025-08-05T16:36:39.158Z,1754411799.158 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T16:36:39.158Z,1754411799.158 [Default:CheckIn](INFO): Running loop #3 2025-08-05T16:36:39.158Z,1754411799.158 [Default:CheckIn] Running Loop=3 2025-08-05T16:36:39.158Z,1754411799.158 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T16:36:39.158Z,1754411799.158 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T16:36:41.168Z,1754411801.168 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163640.00,A,3648.14873,N,12147.22589,W,0.058,4.97,050825,,,D*77 2025-08-05T16:36:41.171Z,1754411801.171 [NAL9602](INFO): GPS fix at 20250805T163640: (36.802479, -121.787098) 2025-08-05T16:36:41.198Z,1754411801.198 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T16:36:41.198Z,1754411801.198 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T16:36:59.172Z,1754411819.172 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0010.lzma 2025-08-05T16:37:10.215Z,1754411830.215 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0010.lzma.bak 2025-08-05T16:37:10.215Z,1754411830.215 [DataOverHttps](INFO): SBD MOMSN=25781847 2025-08-05T16:37:10.683Z,1754411830.683 [NAL9602](INFO): SBD MO Status=2, MOMSN=26323, MT Status=2, MTMSN=0 2025-08-05T16:37:10.683Z,1754411830.683 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-05T16:37:30.477Z,1754411850.477 [NAL9602](INFO): SBD MO Status=0, MOMSN=26323, MT Status=0, MTMSN=0 2025-08-05T16:37:30.477Z,1754411850.477 [NAL9602](INFO): No messages in MT queue 2025-08-05T16:37:36.111Z,1754411856.111 [DataOverHttps](INFO): Sending 1159 bytes from file Logs/20250805T161113/Express0011.lzma 2025-08-05T16:37:47.151Z,1754411867.151 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0011.lzma.bak 2025-08-05T16:37:47.151Z,1754411867.151 [DataOverHttps](INFO): SBD MOMSN=25781850 2025-08-05T16:38:01.190Z,1754411881.190 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T16:38:13.200Z,1754411893.200 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20250805T161113/Express0014.lzma 2025-08-05T16:38:24.242Z,1754411904.242 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0014.lzma.bak 2025-08-05T16:38:24.243Z,1754411904.243 [DataOverHttps](INFO): SBD MOMSN=25781896 2025-08-05T16:38:25.442Z,1754411905.442 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T16:38:25.442Z,1754411905.442 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T16:38:25.443Z,1754411905.443 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T16:43:26.020Z,1754412206.020 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T16:43:26.020Z,1754412206.020 [Default:CheckIn:C.Wait] Stopped 2025-08-05T16:43:26.020Z,1754412206.020 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T16:43:26.020Z,1754412206.020 [Default:CheckIn:D] Running Loop=1 2025-08-05T16:43:26.437Z,1754412206.437 [Default:CheckIn:D] Stopped 2025-08-05T16:43:26.437Z,1754412206.437 [Default:CheckIn:E] Running Loop=1 2025-08-05T16:43:26.825Z,1754412206.825 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.715405 min 2025-08-05T16:43:26.825Z,1754412206.825 [Default:CheckIn:E] Stopped 2025-08-05T16:43:26.825Z,1754412206.825 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T16:43:26.825Z,1754412206.825 [Default:CheckIn] Stopped 2025-08-05T16:43:26.825Z,1754412206.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T16:43:26.825Z,1754412206.825 [Default:CheckIn](INFO): Running loop #4 2025-08-05T16:43:26.825Z,1754412206.825 [Default:CheckIn] Running Loop=4 2025-08-05T16:43:26.826Z,1754412206.826 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T16:43:26.826Z,1754412206.826 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T16:43:28.833Z,1754412208.833 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164328.00,A,3648.14531,N,12147.22310,W,0.058,145.94,050825,,,D*71 2025-08-05T16:43:28.835Z,1754412208.835 [NAL9602](INFO): GPS fix at 20250805T164328: (36.802422, -121.787052) 2025-08-05T16:43:28.847Z,1754412208.847 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T16:43:28.847Z,1754412208.847 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T16:43:36.364Z,1754412216.364 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0016.lzma 2025-08-05T16:43:47.407Z,1754412227.407 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0016.lzma.bak 2025-08-05T16:43:47.407Z,1754412227.407 [DataOverHttps](INFO): SBD MOMSN=25781898 2025-08-05T16:43:52.264Z,1754412232.264 [NAL9602](INFO): SBD MO Status=2, MOMSN=26324, MT Status=2, MTMSN=0 2025-08-05T16:43:52.264Z,1754412232.264 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-05T16:44:02.777Z,1754412242.777 [NAL9602](INFO): SBD MO Status=0, MOMSN=26324, MT Status=0, MTMSN=0 2025-08-05T16:44:02.777Z,1754412242.777 [NAL9602](INFO): No messages in MT queue 2025-08-05T16:44:13.325Z,1754412253.325 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250805T161113/Express0017.lzma 2025-08-05T16:44:24.367Z,1754412264.367 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0017.lzma.bak 2025-08-05T16:44:24.367Z,1754412264.367 [DataOverHttps](INFO): SBD MOMSN=25781901 2025-08-05T16:44:25.414Z,1754412265.414 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T16:44:25.415Z,1754412265.415 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T16:44:25.415Z,1754412265.415 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T16:44:33.479Z,1754412273.479 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T16:49:25.982Z,1754412565.982 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T16:49:25.982Z,1754412565.982 [Default:CheckIn:C.Wait] Stopped 2025-08-05T16:49:25.982Z,1754412565.982 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T16:49:25.983Z,1754412565.983 [Default:CheckIn:D] Running Loop=1 2025-08-05T16:49:26.390Z,1754412566.390 [Default:CheckIn:D] Stopped 2025-08-05T16:49:26.390Z,1754412566.390 [Default:CheckIn:E] Running Loop=1 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.714622 min 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn:E] Stopped 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn] Stopped 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn](INFO): Running loop #5 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn] Running Loop=5 2025-08-05T16:49:26.801Z,1754412566.801 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T16:49:26.802Z,1754412566.802 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T16:49:28.800Z,1754412568.800 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164928.00,A,3648.14442,N,12147.22405,W,0.039,145.94,050825,,,D*7A 2025-08-05T16:49:28.803Z,1754412568.803 [NAL9602](INFO): GPS fix at 20250805T164928: (36.802407, -121.787068) 2025-08-05T16:49:28.846Z,1754412568.846 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T16:49:28.846Z,1754412568.846 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T16:49:36.600Z,1754412576.600 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0019.lzma 2025-08-05T16:49:47.644Z,1754412587.644 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0019.lzma.bak 2025-08-05T16:49:47.644Z,1754412587.644 [DataOverHttps](INFO): SBD MOMSN=25781917 2025-08-05T16:49:54.255Z,1754412594.255 [NAL9602](INFO): SBD MO Status=0, MOMSN=26325, MT Status=0, MTMSN=0 2025-08-05T16:49:54.255Z,1754412594.255 [NAL9602](INFO): No messages in MT queue 2025-08-05T16:50:13.631Z,1754412613.631 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250805T161113/Express0020.lzma 2025-08-05T16:50:24.667Z,1754412624.667 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0020.lzma.bak 2025-08-05T16:50:24.667Z,1754412624.667 [DataOverHttps](INFO): SBD MOMSN=25781923 2025-08-05T16:50:24.963Z,1754412624.963 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T16:50:25.777Z,1754412625.777 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T16:50:25.777Z,1754412625.777 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T16:50:25.777Z,1754412625.777 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T16:55:26.376Z,1754412926.376 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T16:55:26.376Z,1754412926.376 [Default:CheckIn:C.Wait] Stopped 2025-08-05T16:55:26.393Z,1754412926.393 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T16:55:26.393Z,1754412926.393 [Default:CheckIn:D] Running Loop=1 2025-08-05T16:55:26.776Z,1754412926.776 [Default:CheckIn:D] Stopped 2025-08-05T16:55:26.776Z,1754412926.776 [Default:CheckIn:E] Running Loop=1 2025-08-05T16:55:27.184Z,1754412927.184 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.721065 min 2025-08-05T16:55:27.184Z,1754412927.184 [Default:CheckIn:E] Stopped 2025-08-05T16:55:27.185Z,1754412927.185 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T16:55:27.185Z,1754412927.185 [Default:CheckIn] Stopped 2025-08-05T16:55:27.185Z,1754412927.185 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T16:55:27.185Z,1754412927.185 [Default:CheckIn](INFO): Running loop #6 2025-08-05T16:55:27.185Z,1754412927.185 [Default:CheckIn] Running Loop=6 2025-08-05T16:55:27.185Z,1754412927.185 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T16:55:27.185Z,1754412927.185 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T16:55:29.201Z,1754412929.201 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165528.00,A,3648.14899,N,12147.23057,W,0.039,145.94,050825,,,D*7F 2025-08-05T16:55:29.203Z,1754412929.203 [NAL9602](INFO): GPS fix at 20250805T165528: (36.802483, -121.787176) 2025-08-05T16:55:29.214Z,1754412929.214 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T16:55:29.214Z,1754412929.214 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T16:55:37.236Z,1754412937.236 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0022.lzma 2025-08-05T16:55:48.279Z,1754412948.279 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0022.lzma.bak 2025-08-05T16:55:48.279Z,1754412948.279 [DataOverHttps](INFO): SBD MOMSN=25781934 2025-08-05T16:55:49.799Z,1754412949.799 [NAL9602](INFO): SBD MO Status=0, MOMSN=26326, MT Status=0, MTMSN=0 2025-08-05T16:55:49.799Z,1754412949.799 [NAL9602](INFO): No messages in MT queue 2025-08-05T16:56:14.365Z,1754412974.365 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250805T161113/Express0023.lzma 2025-08-05T16:56:20.506Z,1754412980.506 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T16:56:25.407Z,1754412985.407 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0023.lzma.bak 2025-08-05T16:56:25.407Z,1754412985.407 [DataOverHttps](INFO): SBD MOMSN=25781938 2025-08-05T16:56:26.572Z,1754412986.572 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T16:56:26.572Z,1754412986.572 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T16:56:26.572Z,1754412986.572 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:01:27.160Z,1754413287.160 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:01:27.160Z,1754413287.160 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:01:27.160Z,1754413287.160 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:01:27.160Z,1754413287.160 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:01:27.558Z,1754413287.558 [Default:CheckIn:D] Stopped 2025-08-05T17:01:27.559Z,1754413287.559 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:01:27.962Z,1754413287.962 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.734102 min 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn:E] Stopped 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn] Stopped 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn](INFO): Running loop #7 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn] Running Loop=7 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:01:27.963Z,1754413287.963 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:01:29.972Z,1754413289.972 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170129.00,A,3648.14781,N,12147.22500,W,0.019,145.94,050825,,,D*7C 2025-08-05T17:01:29.974Z,1754413289.974 [NAL9602](INFO): GPS fix at 20250805T170129: (36.802464, -121.787083) 2025-08-05T17:01:29.985Z,1754413289.985 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:01:29.985Z,1754413289.985 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:01:38.040Z,1754413298.040 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0025.lzma 2025-08-05T17:01:39.675Z,1754413299.675 [NAL9602](INFO): SBD MO Status=0, MOMSN=26327, MT Status=0, MTMSN=0 2025-08-05T17:01:39.676Z,1754413299.676 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:01:49.083Z,1754413309.083 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0025.lzma.bak 2025-08-05T17:01:49.083Z,1754413309.083 [DataOverHttps](INFO): SBD MOMSN=25781957 2025-08-05T17:02:10.374Z,1754413330.374 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:02:17.613Z,1754413337.613 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250805T161113/Express0026.lzma 2025-08-05T17:02:28.655Z,1754413348.655 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0026.lzma.bak 2025-08-05T17:02:28.655Z,1754413348.655 [DataOverHttps](INFO): SBD MOMSN=25781963 2025-08-05T17:02:29.787Z,1754413349.787 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:02:29.788Z,1754413349.788 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:02:29.788Z,1754413349.788 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:07:30.375Z,1754413650.375 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:07:30.375Z,1754413650.375 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:07:30.375Z,1754413650.375 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:07:30.375Z,1754413650.375 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:07:30.794Z,1754413650.794 [Default:CheckIn:D] Stopped 2025-08-05T17:07:30.794Z,1754413650.794 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.788025 min 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn:E] Stopped 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn] Stopped 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn](INFO): Running loop #8 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn] Running Loop=8 2025-08-05T17:07:31.186Z,1754413651.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:07:31.187Z,1754413651.187 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:07:33.200Z,1754413653.200 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170732.00,A,3648.14920,N,12147.22959,W,0.019,145.94,050825,,,D*75 2025-08-05T17:07:33.202Z,1754413653.202 [NAL9602](INFO): GPS fix at 20250805T170732: (36.802487, -121.787160) 2025-08-05T17:07:33.218Z,1754413653.218 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:07:33.218Z,1754413653.218 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:07:41.236Z,1754413661.236 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0028.lzma 2025-08-05T17:07:49.355Z,1754413669.355 [NAL9602](INFO): SBD MO Status=0, MOMSN=26328, MT Status=0, MTMSN=0 2025-08-05T17:07:49.355Z,1754413669.355 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:07:52.279Z,1754413672.279 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0028.lzma.bak 2025-08-05T17:07:52.279Z,1754413672.279 [DataOverHttps](INFO): SBD MOMSN=25782108 2025-08-05T17:08:18.316Z,1754413698.316 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250805T161113/Express0029.lzma 2025-08-05T17:08:20.061Z,1754413700.061 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:08:29.359Z,1754413709.359 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0029.lzma.bak 2025-08-05T17:08:29.359Z,1754413709.359 [DataOverHttps](INFO): SBD MOMSN=25782155 2025-08-05T17:08:30.573Z,1754413710.573 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:08:30.573Z,1754413710.573 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:08:30.573Z,1754413710.573 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:13:31.147Z,1754414011.147 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:13:31.148Z,1754414011.148 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:13:31.148Z,1754414011.148 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:13:31.148Z,1754414011.148 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:13:31.562Z,1754414011.562 [Default:CheckIn:D] Stopped 2025-08-05T17:13:31.562Z,1754414011.562 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:13:31.956Z,1754414011.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.800830 min 2025-08-05T17:13:31.956Z,1754414011.956 [Default:CheckIn:E] Stopped 2025-08-05T17:13:31.957Z,1754414011.957 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:13:31.957Z,1754414011.957 [Default:CheckIn] Stopped 2025-08-05T17:13:31.957Z,1754414011.957 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:13:31.958Z,1754414011.958 [Default:CheckIn](INFO): Running loop #9 2025-08-05T17:13:31.958Z,1754414011.958 [Default:CheckIn] Running Loop=9 2025-08-05T17:13:31.958Z,1754414011.958 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:13:31.958Z,1754414011.958 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:13:33.968Z,1754414013.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171333.00,A,3648.14735,N,12147.22400,W,0.058,145.94,050825,,,D*7F 2025-08-05T17:13:33.971Z,1754414013.971 [NAL9602](INFO): GPS fix at 20250805T171333: (36.802456, -121.787067) 2025-08-05T17:13:33.989Z,1754414013.989 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:13:33.990Z,1754414013.990 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:13:41.352Z,1754414021.352 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0031.lzma 2025-08-05T17:13:52.395Z,1754414032.395 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0031.lzma.bak 2025-08-05T17:13:52.395Z,1754414032.395 [DataOverHttps](INFO): SBD MOMSN=25782235 2025-08-05T17:13:58.608Z,1754414038.608 [NAL9602](INFO): SBD MO Status=2, MOMSN=26329, MT Status=2, MTMSN=0 2025-08-05T17:13:58.608Z,1754414038.608 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-05T17:14:18.413Z,1754414058.413 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250805T161113/Express0032.lzma 2025-08-05T17:14:29.455Z,1754414069.455 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0032.lzma.bak 2025-08-05T17:14:29.455Z,1754414069.455 [DataOverHttps](INFO): SBD MOMSN=25782267 2025-08-05T17:14:30.542Z,1754414070.542 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:14:30.542Z,1754414070.542 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:14:30.542Z,1754414070.542 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:15:10.131Z,1754414110.131 [NAL9602](INFO): SBD MO Status=0, MOMSN=26329, MT Status=0, MTMSN=0 2025-08-05T17:15:10.131Z,1754414110.131 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:15:40.830Z,1754414140.830 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:19:31.127Z,1754414371.127 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:19:31.127Z,1754414371.127 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:19:31.128Z,1754414371.128 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:19:31.128Z,1754414371.128 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:19:31.539Z,1754414371.539 [Default:CheckIn:D] Stopped 2025-08-05T17:19:31.539Z,1754414371.539 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:19:31.950Z,1754414371.950 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.800444 min 2025-08-05T17:19:31.950Z,1754414371.950 [Default:CheckIn:E] Stopped 2025-08-05T17:19:31.950Z,1754414371.950 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:19:31.950Z,1754414371.950 [Default:CheckIn] Stopped 2025-08-05T17:19:31.951Z,1754414371.951 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:19:31.951Z,1754414371.951 [Default:CheckIn](INFO): Running loop #10 2025-08-05T17:19:31.951Z,1754414371.951 [Default:CheckIn] Running Loop=10 2025-08-05T17:19:31.951Z,1754414371.951 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:19:31.951Z,1754414371.951 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:19:33.947Z,1754414373.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171933.00,A,3648.14552,N,12147.22230,W,0.000,145.94,050825,,,D*7E 2025-08-05T17:19:33.950Z,1754414373.950 [NAL9602](INFO): GPS fix at 20250805T171933: (36.802425, -121.787038) 2025-08-05T17:19:33.961Z,1754414373.961 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:19:33.961Z,1754414373.961 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:19:41.692Z,1754414381.692 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0034.lzma 2025-08-05T17:19:50.508Z,1754414390.508 [NAL9602](INFO): SBD MO Status=0, MOMSN=26330, MT Status=0, MTMSN=0 2025-08-05T17:19:50.508Z,1754414390.508 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:19:52.735Z,1754414392.735 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0034.lzma.bak 2025-08-05T17:19:52.735Z,1754414392.735 [DataOverHttps](INFO): SBD MOMSN=25782283 2025-08-05T17:20:20.057Z,1754414420.057 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250805T161113/Express0035.lzma 2025-08-05T17:20:21.230Z,1754414421.230 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:20:31.099Z,1754414431.099 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0035.lzma.bak 2025-08-05T17:20:31.099Z,1754414431.099 [DataOverHttps](INFO): SBD MOMSN=25782290 2025-08-05T17:20:32.144Z,1754414432.144 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:20:32.145Z,1754414432.145 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:20:32.145Z,1754414432.145 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:25:32.762Z,1754414732.762 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:25:32.762Z,1754414732.762 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:25:32.762Z,1754414732.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:25:32.762Z,1754414732.762 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:25:33.176Z,1754414733.176 [Default:CheckIn:D] Stopped 2025-08-05T17:25:33.176Z,1754414733.176 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:25:33.594Z,1754414733.594 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.827734 min 2025-08-05T17:25:33.594Z,1754414733.594 [Default:CheckIn:E] Stopped 2025-08-05T17:25:33.594Z,1754414733.594 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:25:33.594Z,1754414733.594 [Default:CheckIn] Stopped 2025-08-05T17:25:33.594Z,1754414733.594 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:25:33.594Z,1754414733.594 [Default:CheckIn](INFO): Running loop #11 2025-08-05T17:25:33.594Z,1754414733.594 [Default:CheckIn] Running Loop=11 2025-08-05T17:25:33.595Z,1754414733.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:25:33.595Z,1754414733.595 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:25:35.581Z,1754414735.581 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172534.00,A,3648.14925,N,12147.22663,W,0.039,0.00,050825,,,D*7F 2025-08-05T17:25:35.583Z,1754414735.583 [NAL9602](INFO): GPS fix at 20250805T172534: (36.802487, -121.787110) 2025-08-05T17:25:35.594Z,1754414735.594 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:25:35.594Z,1754414735.594 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:25:43.124Z,1754414743.124 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0037.lzma 2025-08-05T17:25:54.181Z,1754414754.181 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0037.lzma.bak 2025-08-05T17:25:54.181Z,1754414754.181 [DataOverHttps](INFO): SBD MOMSN=25782449 2025-08-05T17:25:57.058Z,1754414757.058 [NAL9602](INFO): SBD MO Status=2, MOMSN=26331, MT Status=2, MTMSN=0 2025-08-05T17:25:57.058Z,1754414757.058 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-05T17:26:20.086Z,1754414780.086 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250805T161113/Express0038.lzma 2025-08-05T17:26:21.342Z,1754414781.342 [NAL9602](INFO): SBD MO Status=0, MOMSN=26331, MT Status=0, MTMSN=0 2025-08-05T17:26:21.342Z,1754414781.342 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:26:31.132Z,1754414791.132 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0038.lzma.bak 2025-08-05T17:26:31.132Z,1754414791.132 [DataOverHttps](INFO): SBD MOMSN=25782454 2025-08-05T17:26:32.159Z,1754414792.159 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:26:32.159Z,1754414792.159 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:26:32.159Z,1754414792.159 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:26:51.967Z,1754414811.967 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:27:49.737Z,1754414869.737 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:28:03.878Z,1754414883.878 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:28:18.017Z,1754414898.017 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:28:32.562Z,1754414912.562 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:28:47.108Z,1754414927.108 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:28:51.970Z,1754414931.970 [DataOverHttps](IMPORTANT): SBD MTMSN=20250805T172850 2025-08-05T17:28:59.633Z,1754414939.633 [DataOverHttps](INFO): Received command: failc 2025-08-05T17:28:59.637Z,1754414939.637 [CommandExec](IMPORTANT): got command failComponent 2025-08-05T17:28:59.638Z,1754414939.638 [CommandExec](IMPORTANT): Failed components: 2025-08-05T17:28:59.638Z,1754414939.638 [CommandExec](IMPORTANT): No failed Components. 2025-08-05T17:29:01.246Z,1754414941.246 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:29:15.014Z,1754414955.014 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:29:29.120Z,1754414969.120 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:29:43.275Z,1754414983.275 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:29:57.405Z,1754414997.405 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:31:32.776Z,1754415092.776 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:31:32.776Z,1754415092.776 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:31:32.776Z,1754415092.776 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:31:32.776Z,1754415092.776 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:31:33.170Z,1754415093.170 [Default:CheckIn:D] Stopped 2025-08-05T17:31:33.171Z,1754415093.171 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:31:33.565Z,1754415093.565 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.827637 min 2025-08-05T17:31:33.565Z,1754415093.565 [Default:CheckIn:E] Stopped 2025-08-05T17:31:33.565Z,1754415093.565 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:31:33.565Z,1754415093.565 [Default:CheckIn] Stopped 2025-08-05T17:31:33.565Z,1754415093.565 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:31:33.565Z,1754415093.565 [Default:CheckIn](INFO): Running loop #12 2025-08-05T17:31:33.565Z,1754415093.565 [Default:CheckIn] Running Loop=12 2025-08-05T17:31:33.566Z,1754415093.566 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:31:33.566Z,1754415093.566 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:31:35.584Z,1754415095.584 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173134.00,A,3648.14806,N,12147.22353,W,0.039,0.00,050825,,,D*7C 2025-08-05T17:31:35.586Z,1754415095.586 [NAL9602](INFO): GPS fix at 20250805T173134: (36.802468, -121.787059) 2025-08-05T17:31:35.597Z,1754415095.597 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:31:35.597Z,1754415095.597 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:31:51.172Z,1754415111.172 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0040.lzma 2025-08-05T17:32:02.215Z,1754415122.215 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0040.lzma.bak 2025-08-05T17:32:02.215Z,1754415122.215 [DataOverHttps](INFO): SBD MOMSN=25782480 2025-08-05T17:32:02.651Z,1754415122.651 [NAL9602](INFO): SBD MO Status=2, MOMSN=26332, MT Status=2, MTMSN=0 2025-08-05T17:32:02.652Z,1754415122.652 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-05T17:32:26.195Z,1754415146.195 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-08-05T17:32:28.457Z,1754415148.457 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20250805T161113/Express0041.lzma 2025-08-05T17:32:32.941Z,1754415152.941 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:32:37.401Z,1754415157.401 [NAL9602](INFO): SBD MO Status=2, MOMSN=26332, MT Status=2, MTMSN=0 2025-08-05T17:32:37.402Z,1754415157.402 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-05T17:32:39.499Z,1754415159.499 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0041.lzma.bak 2025-08-05T17:32:39.499Z,1754415159.499 [DataOverHttps](INFO): SBD MOMSN=25782483 2025-08-05T17:32:47.917Z,1754415167.917 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:33:02.839Z,1754415182.839 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:33:05.668Z,1754415185.668 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20250805T161113/Express0044.lzma 2025-08-05T17:33:16.711Z,1754415196.711 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0044.lzma.bak 2025-08-05T17:33:16.711Z,1754415196.711 [DataOverHttps](INFO): SBD MOMSN=25782491 2025-08-05T17:33:17.851Z,1754415197.851 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:33:17.851Z,1754415197.851 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:33:17.851Z,1754415197.851 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:33:18.188Z,1754415198.188 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:33:24.659Z,1754415204.659 [NAL9602](INFO): SBD MO Status=2, MOMSN=26332, MT Status=2, MTMSN=0 2025-08-05T17:33:24.659Z,1754415204.659 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-05T17:33:33.137Z,1754415213.137 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:33:48.488Z,1754415228.488 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:34:03.437Z,1754415243.437 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:34:09.923Z,1754415249.923 [NAL9602](INFO): SBD MO Status=0, MOMSN=26332, MT Status=0, MTMSN=0 2025-08-05T17:34:09.923Z,1754415249.923 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:34:18.791Z,1754415258.791 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:34:33.737Z,1754415273.737 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:34:40.614Z,1754415280.614 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:34:48.283Z,1754415288.283 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2025-08-05T17:37:09.400Z,1754415429.400 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:37:15.400Z,1754415435.400 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:37:27.927Z,1754415447.927 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:37:40.044Z,1754415460.044 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:37:52.166Z,1754415472.166 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:38:04.702Z,1754415484.702 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:38:17.225Z,1754415497.225 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:38:18.439Z,1754415498.439 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:38:18.439Z,1754415498.439 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:38:18.439Z,1754415498.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:38:18.439Z,1754415498.439 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:38:18.851Z,1754415498.851 [Default:CheckIn:D] Stopped 2025-08-05T17:38:18.851Z,1754415498.851 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.588981 min 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn:E] Stopped 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn] Stopped 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn](INFO): Running loop #13 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn] Running Loop=13 2025-08-05T17:38:19.269Z,1754415499.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:38:19.270Z,1754415499.270 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:38:21.260Z,1754415501.260 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173820.00,A,3648.15207,N,12147.22695,W,1.652,17.21,050825,,,D*4A 2025-08-05T17:38:21.262Z,1754415501.262 [NAL9602](INFO): GPS fix at 20250805T173820: (36.802535, -121.787116) 2025-08-05T17:38:21.273Z,1754415501.273 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:38:21.273Z,1754415501.273 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:38:28.564Z,1754415508.564 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0046.lzma 2025-08-05T17:38:29.333Z,1754415509.333 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:38:39.607Z,1754415519.607 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0046.lzma.bak 2025-08-05T17:38:39.607Z,1754415519.607 [DataOverHttps](INFO): SBD MOMSN=25782627 2025-08-05T17:38:40.244Z,1754415520.244 [NAL9602](INFO): SBD MO Status=0, MOMSN=26333, MT Status=0, MTMSN=0 2025-08-05T17:38:40.244Z,1754415520.244 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:38:41.452Z,1754415521.452 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:38:53.573Z,1754415533.573 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:39:05.733Z,1754415545.733 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250805T161113/Express0047.lzma 2025-08-05T17:39:06.120Z,1754415546.120 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:39:10.990Z,1754415550.990 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:39:16.775Z,1754415556.775 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0047.lzma.bak 2025-08-05T17:39:16.775Z,1754415556.775 [DataOverHttps](INFO): SBD MOMSN=25782651 2025-08-05T17:39:17.848Z,1754415557.848 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:39:17.849Z,1754415557.849 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:39:17.849Z,1754415557.849 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:39:18.647Z,1754415558.647 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:39:31.170Z,1754415571.170 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:41:32.433Z,1754415692.433 [Sonardyne_Nano](INFO): Battery at maximum, disabling charging 2025-08-05T17:41:53.829Z,1754415713.829 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:42:08.776Z,1754415728.776 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:42:24.130Z,1754415744.130 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:42:40.289Z,1754415760.289 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:42:55.844Z,1754415775.844 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:43:11.397Z,1754415791.397 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:43:26.344Z,1754415806.344 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:43:41.292Z,1754415821.292 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:43:56.241Z,1754415836.241 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:44:10.805Z,1754415850.805 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2025-08-05T17:44:18.493Z,1754415858.493 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:44:18.494Z,1754415858.494 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:44:18.494Z,1754415858.494 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:44:18.494Z,1754415858.494 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:44:18.886Z,1754415858.886 [Default:CheckIn:D] Stopped 2025-08-05T17:44:18.886Z,1754415858.886 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:44:19.301Z,1754415859.301 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.589559 min 2025-08-05T17:44:19.301Z,1754415859.301 [Default:CheckIn:E] Stopped 2025-08-05T17:44:19.301Z,1754415859.301 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:44:19.301Z,1754415859.301 [Default:CheckIn] Stopped 2025-08-05T17:44:19.301Z,1754415859.301 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:44:19.301Z,1754415859.301 [Default:CheckIn](INFO): Running loop #14 2025-08-05T17:44:19.301Z,1754415859.301 [Default:CheckIn] Running Loop=14 2025-08-05T17:44:19.302Z,1754415859.302 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:44:19.302Z,1754415859.302 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:44:21.292Z,1754415861.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174420.00,A,3648.15296,N,12147.22208,W,0.525,82.06,050825,,,D*42 2025-08-05T17:44:21.294Z,1754415861.294 [NAL9602](INFO): GPS fix at 20250805T174420: (36.802549, -121.787035) 2025-08-05T17:44:21.305Z,1754415861.305 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:44:21.305Z,1754415861.305 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:44:28.725Z,1754415868.725 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0049.lzma 2025-08-05T17:44:35.036Z,1754415875.036 [NAL9602](INFO): SBD MO Status=0, MOMSN=26334, MT Status=0, MTMSN=0 2025-08-05T17:44:35.037Z,1754415875.037 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:44:39.767Z,1754415879.767 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0049.lzma.bak 2025-08-05T17:44:39.767Z,1754415879.767 [DataOverHttps](INFO): SBD MOMSN=25782735 2025-08-05T17:45:05.787Z,1754415905.787 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:45:05.818Z,1754415905.818 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250805T161113/Express0050.lzma 2025-08-05T17:45:16.863Z,1754415916.863 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0050.lzma.bak 2025-08-05T17:45:16.863Z,1754415916.863 [DataOverHttps](INFO): SBD MOMSN=25782749 2025-08-05T17:45:17.896Z,1754415917.896 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:45:17.897Z,1754415917.897 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:45:17.897Z,1754415917.897 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:46:39.052Z,1754415999.052 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:46:52.805Z,1754416012.805 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:47:06.980Z,1754416026.980 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:47:20.312Z,1754416040.312 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:47:33.645Z,1754416053.645 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:47:47.380Z,1754416067.380 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:48:01.522Z,1754416081.522 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:48:15.259Z,1754416095.259 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:48:29.398Z,1754416109.398 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:48:43.132Z,1754416123.132 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:50:18.558Z,1754416218.558 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:50:18.558Z,1754416218.558 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:50:18.558Z,1754416218.558 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:50:18.558Z,1754416218.558 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:50:18.922Z,1754416218.922 [Default:CheckIn:D] Stopped 2025-08-05T17:50:18.922Z,1754416218.922 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:50:19.329Z,1754416219.329 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.590169 min 2025-08-05T17:50:19.329Z,1754416219.329 [Default:CheckIn:E] Stopped 2025-08-05T17:50:19.329Z,1754416219.329 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:50:19.329Z,1754416219.329 [Default:CheckIn] Stopped 2025-08-05T17:50:19.329Z,1754416219.329 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:50:19.330Z,1754416219.330 [Default:CheckIn](INFO): Running loop #15 2025-08-05T17:50:19.330Z,1754416219.330 [Default:CheckIn] Running Loop=15 2025-08-05T17:50:19.330Z,1754416219.330 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:50:19.330Z,1754416219.330 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:50:21.312Z,1754416221.312 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175020.00,A,3648.15076,N,12147.21569,W,0.311,168.38,050825,,,A*74 2025-08-05T17:50:21.314Z,1754416221.314 [NAL9602](INFO): GPS fix at 20250805T175020: (36.802513, -121.786928) 2025-08-05T17:50:21.350Z,1754416221.350 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:50:21.350Z,1754416221.350 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:50:29.356Z,1754416229.356 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250805T161113/Courier0052.lzma 2025-08-05T17:50:36.258Z,1754416236.258 [NAL9602](INFO): SBD MO Status=0, MOMSN=26335, MT Status=0, MTMSN=0 2025-08-05T17:50:36.258Z,1754416236.258 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:50:40.399Z,1754416240.399 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0052.lzma.bak 2025-08-05T17:50:40.399Z,1754416240.399 [DataOverHttps](INFO): SBD MOMSN=25782798 2025-08-05T17:51:06.513Z,1754416266.513 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250805T161113/Express0053.lzma 2025-08-05T17:51:06.960Z,1754416266.960 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:51:17.555Z,1754416277.555 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0053.lzma.bak 2025-08-05T17:51:17.555Z,1754416277.555 [DataOverHttps](INFO): SBD MOMSN=25782802 2025-08-05T17:51:18.702Z,1754416278.702 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:51:18.702Z,1754416278.702 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:51:18.702Z,1754416278.702 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T17:51:19.481Z,1754416279.481 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:51:34.437Z,1754416294.437 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:51:49.385Z,1754416309.385 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:52:04.734Z,1754416324.734 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:52:20.084Z,1754416340.084 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:52:36.258Z,1754416356.258 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:52:51.257Z,1754416371.257 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:53:06.193Z,1754416386.193 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:53:21.143Z,1754416401.143 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-05T17:53:35.685Z,1754416415.685 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2025-08-05T17:55:38.101Z,1754416538.101 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-05T17:55:38.102Z,1754416538.102 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-08-05T17:55:38.102Z,1754416538.102 [BPC1](ERROR): Battery stick #37 (s/n: 0181) reported OVER_TEMP_ALARM. Status code: 0x1717. 2025-08-05T17:55:38.103Z,1754416538.103 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-05T17:55:38.104Z,1754416538.104 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-05T17:55:38.105Z,1754416538.105 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2025-08-05T17:55:38.105Z,1754416538.105 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 4. 2025-08-05T17:55:38.108Z,1754416538.108 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2025-08-05T17:56:19.323Z,1754416579.323 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T17:56:19.323Z,1754416579.323 [Default:CheckIn:C.Wait] Stopped 2025-08-05T17:56:19.323Z,1754416579.323 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T17:56:19.323Z,1754416579.323 [Default:CheckIn:D] Running Loop=1 2025-08-05T17:56:19.734Z,1754416579.734 [Default:CheckIn:D] Stopped 2025-08-05T17:56:19.734Z,1754416579.734 [Default:CheckIn:E] Running Loop=1 2025-08-05T17:56:20.148Z,1754416580.148 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.603695 min 2025-08-05T17:56:20.148Z,1754416580.148 [Default:CheckIn:E] Stopped 2025-08-05T17:56:20.148Z,1754416580.148 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T17:56:20.148Z,1754416580.148 [Default:CheckIn] Stopped 2025-08-05T17:56:20.148Z,1754416580.148 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T17:56:20.149Z,1754416580.149 [Default:CheckIn](INFO): Running loop #16 2025-08-05T17:56:20.149Z,1754416580.149 [Default:CheckIn] Running Loop=16 2025-08-05T17:56:20.149Z,1754416580.149 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T17:56:20.149Z,1754416580.149 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T17:56:22.141Z,1754416582.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175621.00,A,3648.16336,N,12147.19877,W,0.505,97.75,050825,,,A*45 2025-08-05T17:56:22.143Z,1754416582.143 [NAL9602](INFO): GPS fix at 20250805T175621: (36.802723, -121.786646) 2025-08-05T17:56:22.155Z,1754416582.155 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T17:56:22.155Z,1754416582.155 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T17:56:29.900Z,1754416589.900 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250805T161113/Courier0055.lzma 2025-08-05T17:56:40.955Z,1754416600.955 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0055.lzma.bak 2025-08-05T17:56:40.955Z,1754416600.955 [DataOverHttps](INFO): SBD MOMSN=25782946 2025-08-05T17:56:41.536Z,1754416601.536 [NAL9602](INFO): SBD MO Status=0, MOMSN=26336, MT Status=0, MTMSN=0 2025-08-05T17:56:41.536Z,1754416601.536 [NAL9602](INFO): No messages in MT queue 2025-08-05T17:57:07.389Z,1754416627.389 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20250805T161113/Express0056.lzma 2025-08-05T17:57:12.262Z,1754416632.262 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T17:57:18.431Z,1754416638.431 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0056.lzma.bak 2025-08-05T17:57:18.431Z,1754416638.431 [DataOverHttps](INFO): SBD MOMSN=25782951 2025-08-05T17:57:19.541Z,1754416639.541 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T17:57:19.541Z,1754416639.541 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T17:57:19.541Z,1754416639.541 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T18:02:20.157Z,1754416940.157 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T18:02:20.158Z,1754416940.158 [Default:CheckIn:C.Wait] Stopped 2025-08-05T18:02:20.158Z,1754416940.158 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T18:02:20.158Z,1754416940.158 [Default:CheckIn:D] Running Loop=1 2025-08-05T18:02:20.564Z,1754416940.564 [Default:CheckIn:D] Stopped 2025-08-05T18:02:20.564Z,1754416940.564 [Default:CheckIn:E] Running Loop=1 2025-08-05T18:02:20.976Z,1754416940.976 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.617529 min 2025-08-05T18:02:20.976Z,1754416940.976 [Default:CheckIn:E] Stopped 2025-08-05T18:02:20.976Z,1754416940.976 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T18:02:20.976Z,1754416940.976 [Default:CheckIn] Stopped 2025-08-05T18:02:20.976Z,1754416940.976 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T18:02:20.977Z,1754416940.977 [Default:CheckIn](INFO): Running loop #17 2025-08-05T18:02:20.977Z,1754416940.977 [Default:CheckIn] Running Loop=17 2025-08-05T18:02:20.977Z,1754416940.977 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T18:02:20.977Z,1754416940.977 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T18:02:22.977Z,1754416942.977 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180222.00,A,3648.52384,N,12147.13805,W,5.695,278.88,050825,,,A*70 2025-08-05T18:02:22.980Z,1754416942.980 [NAL9602](INFO): GPS fix at 20250805T180222: (36.808731, -121.785634) 2025-08-05T18:02:22.991Z,1754416942.991 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T18:02:22.991Z,1754416942.991 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T18:02:30.012Z,1754416950.012 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0058.lzma 2025-08-05T18:02:41.055Z,1754416961.055 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0058.lzma.bak 2025-08-05T18:02:41.055Z,1754416961.055 [DataOverHttps](INFO): SBD MOMSN=25782991 2025-08-05T18:02:41.166Z,1754416961.166 [NAL9602](INFO): SBD MO Status=0, MOMSN=26337, MT Status=0, MTMSN=0 2025-08-05T18:02:41.167Z,1754416961.167 [NAL9602](INFO): No messages in MT queue 2025-08-05T18:03:07.757Z,1754416987.757 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250805T161113/Express0059.lzma 2025-08-05T18:03:11.874Z,1754416991.874 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T18:03:18.799Z,1754416998.799 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0059.lzma.bak 2025-08-05T18:03:18.799Z,1754416998.799 [DataOverHttps](INFO): SBD MOMSN=25782995 2025-08-05T18:03:19.969Z,1754416999.969 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T18:03:19.969Z,1754416999.969 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T18:03:19.969Z,1754416999.969 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T18:08:20.541Z,1754417300.541 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T18:08:20.541Z,1754417300.541 [Default:CheckIn:C.Wait] Stopped 2025-08-05T18:08:20.541Z,1754417300.541 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T18:08:20.541Z,1754417300.541 [Default:CheckIn:D] Running Loop=1 2025-08-05T18:08:20.947Z,1754417300.947 [Default:CheckIn:D] Stopped 2025-08-05T18:08:20.947Z,1754417300.947 [Default:CheckIn:E] Running Loop=1 2025-08-05T18:08:21.344Z,1754417301.344 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.623918 min 2025-08-05T18:08:21.344Z,1754417301.344 [Default:CheckIn:E] Stopped 2025-08-05T18:08:21.345Z,1754417301.345 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T18:08:21.345Z,1754417301.345 [Default:CheckIn] Stopped 2025-08-05T18:08:21.345Z,1754417301.345 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T18:08:21.345Z,1754417301.345 [Default:CheckIn](INFO): Running loop #18 2025-08-05T18:08:21.345Z,1754417301.345 [Default:CheckIn] Running Loop=18 2025-08-05T18:08:21.345Z,1754417301.345 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T18:08:21.345Z,1754417301.345 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T18:08:23.356Z,1754417303.356 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180822.00,A,3647.93669,N,12148.86690,W,19.438,250.91,050825,,,D*40 2025-08-05T18:08:23.358Z,1754417303.358 [NAL9602](INFO): GPS fix at 20250805T180822: (36.798945, -121.814448) 2025-08-05T18:08:23.369Z,1754417303.369 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T18:08:23.369Z,1754417303.369 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T18:08:30.696Z,1754417310.696 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0061.lzma 2025-08-05T18:08:36.395Z,1754417316.395 [NAL9602](INFO): SBD MO Status=0, MOMSN=26338, MT Status=0, MTMSN=0 2025-08-05T18:08:36.395Z,1754417316.395 [NAL9602](INFO): No messages in MT queue 2025-08-05T18:08:41.739Z,1754417321.739 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0061.lzma.bak 2025-08-05T18:08:41.739Z,1754417321.739 [DataOverHttps](INFO): SBD MOMSN=25783127 2025-08-05T18:09:07.098Z,1754417347.098 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T18:09:08.937Z,1754417348.937 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20250805T161113/Express0062.lzma 2025-08-05T18:09:19.979Z,1754417359.979 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0062.lzma.bak 2025-08-05T18:09:19.979Z,1754417359.979 [DataOverHttps](INFO): SBD MOMSN=25783131 2025-08-05T18:09:21.256Z,1754417361.256 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T18:09:21.256Z,1754417361.256 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T18:09:21.256Z,1754417361.256 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T18:14:21.829Z,1754417661.829 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T18:14:21.829Z,1754417661.829 [Default:CheckIn:C.Wait] Stopped 2025-08-05T18:14:21.829Z,1754417661.829 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T18:14:21.829Z,1754417661.829 [Default:CheckIn:D] Running Loop=1 2025-08-05T18:14:22.245Z,1754417662.245 [Default:CheckIn:D] Stopped 2025-08-05T18:14:22.245Z,1754417662.245 [Default:CheckIn:E] Running Loop=1 2025-08-05T18:14:22.651Z,1754417662.651 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.645540 min 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn:E] Stopped 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn] Stopped 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn](INFO): Running loop #19 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn] Running Loop=19 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T18:14:22.652Z,1754417662.652 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T18:14:24.652Z,1754417664.652 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181423.00,A,3647.79911,N,12150.90637,W,0.350,69.85,050825,,,D*47 2025-08-05T18:14:24.654Z,1754417664.654 [NAL9602](INFO): GPS fix at 20250805T181423: (36.796652, -121.848439) 2025-08-05T18:14:24.690Z,1754417664.690 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T18:14:24.690Z,1754417664.690 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T18:15:06.719Z,1754417706.719 [NAL9602](INFO): SBD MO Status=0, MOMSN=26339, MT Status=0, MTMSN=0 2025-08-05T18:15:06.719Z,1754417706.719 [NAL9602](INFO): No messages in MT queue 2025-08-05T18:15:08.680Z,1754417708.680 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0064.lzma 2025-08-05T18:15:19.723Z,1754417719.723 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0064.lzma.bak 2025-08-05T18:15:19.723Z,1754417719.723 [DataOverHttps](INFO): SBD MOMSN=25783134 2025-08-05T18:15:37.422Z,1754417737.422 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T18:15:45.705Z,1754417745.705 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250805T161113/Express0065.lzma 2025-08-05T18:15:57.759Z,1754417757.759 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0065.lzma.bak 2025-08-05T18:15:57.759Z,1754417757.759 [DataOverHttps](INFO): SBD MOMSN=25783214 2025-08-05T18:15:58.844Z,1754417758.844 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T18:15:58.844Z,1754417758.844 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T18:15:58.844Z,1754417758.844 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T18:20:59.433Z,1754418059.433 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-05T18:20:59.433Z,1754418059.433 [Default:CheckIn:C.Wait] Stopped 2025-08-05T18:20:59.433Z,1754418059.433 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-05T18:20:59.434Z,1754418059.434 [Default:CheckIn:D] Running Loop=1 2025-08-05T18:20:59.837Z,1754418059.837 [Default:CheckIn:D] Stopped 2025-08-05T18:20:59.837Z,1754418059.837 [Default:CheckIn:E] Running Loop=1 2025-08-05T18:21:00.242Z,1754418060.242 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.272087 min 2025-08-05T18:21:00.242Z,1754418060.242 [Default:CheckIn:E] Stopped 2025-08-05T18:21:00.242Z,1754418060.242 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-05T18:21:00.242Z,1754418060.242 [Default:CheckIn] Stopped 2025-08-05T18:21:00.243Z,1754418060.243 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-05T18:21:00.243Z,1754418060.243 [Default:CheckIn](INFO): Running loop #20 2025-08-05T18:21:00.243Z,1754418060.243 [Default:CheckIn] Running Loop=20 2025-08-05T18:21:00.243Z,1754418060.243 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-05T18:21:00.243Z,1754418060.243 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-05T18:21:02.252Z,1754418062.252 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182101.00,A,3647.83525,N,12150.86051,W,0.972,5.65,050825,,,D*70 2025-08-05T18:21:02.262Z,1754418062.262 [NAL9602](INFO): GPS fix at 20250805T182101: (36.797254, -121.847675) 2025-08-05T18:21:02.274Z,1754418062.274 [Default:CheckIn:Read_GPS] Stopped 2025-08-05T18:21:02.274Z,1754418062.274 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-05T18:21:09.988Z,1754418069.988 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250805T161113/Courier0067.lzma 2025-08-05T18:21:15.187Z,1754418075.187 [NAL9602](INFO): SBD MO Status=0, MOMSN=26340, MT Status=0, MTMSN=0 2025-08-05T18:21:15.188Z,1754418075.188 [NAL9602](INFO): No messages in MT queue 2025-08-05T18:21:21.031Z,1754418081.031 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Courier0067.lzma.bak 2025-08-05T18:21:21.031Z,1754418081.031 [DataOverHttps](INFO): SBD MOMSN=25783261 2025-08-05T18:21:45.886Z,1754418105.886 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-05T18:21:47.049Z,1754418107.049 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250805T161113/Express0068.lzma 2025-08-05T18:21:58.091Z,1754418118.091 [DataOverHttps](INFO): Moved sent file to Logs/20250805T161113/Express0068.lzma.bak 2025-08-05T18:21:58.091Z,1754418118.091 [DataOverHttps](INFO): SBD MOMSN=25783265 2025-08-05T18:21:59.226Z,1754418119.226 [Default:CheckIn:Read_Iridium] Stopped 2025-08-05T18:21:59.226Z,1754418119.226 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-05T18:21:59.226Z,1754418119.226 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-05T18:23:30.134Z,1754418210.134 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -21.00 mm (1 active estimators). 2025-08-05T18:24:00.929Z,1754418240.929 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-05T18:24:11.221Z,1754418251.221 [Waterlinked](INFO): Powering down 2025-08-05T18:24:32.053Z,1754418272.053 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-05T18:25:03.605Z,1754418303.605 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-05T18:25:52.694Z,1754418352.694 [DataOverHttps](IMPORTANT): SBD MTMSN=20250805T182551