2025-03-11T15:53:06.410Z,1741708386.410 [Supervisor](DEBUG): Initializing supervisor. 2025-03-11T15:53:06.416Z,1741708386.416 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-03-11T15:53:06.416Z,1741708386.416 [SyncHandler](INFO): Protected caller Thread ID is 982 2025-03-11T15:53:06.417Z,1741708386.417 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-03-11T15:53:06.418Z,1741708386.418 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-03-11T15:53:06.418Z,1741708386.418 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 983 2025-03-11T15:53:06.423Z,1741708386.423 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-03-11T15:53:06.444Z,1741708386.444 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-03-11T15:53:06.445Z,1741708386.445 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-03-11T15:53:06.445Z,1741708386.445 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 984 2025-03-11T15:53:06.450Z,1741708386.450 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-03-11T15:53:06.451Z,1741708386.451 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-03-11T15:53:06.451Z,1741708386.451 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 985 2025-03-11T15:53:06.453Z,1741708386.453 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-03-11T15:53:06.455Z,1741708386.455 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-03-11T15:53:06.455Z,1741708386.455 [logger ThreadHandler](INFO): Protected caller Thread ID is 986 2025-03-11T15:53:06.459Z,1741708386.459 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-03-11T15:53:06.460Z,1741708386.460 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-03-11T15:53:06.461Z,1741708386.461 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-03-11T15:53:06.767Z,1741708386.767 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-03-11T15:53:06.767Z,1741708386.767 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-03-11T15:53:06.862Z,1741708386.862 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-03-11T15:53:07.461Z,1741708387.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-03-11T15:53:07.462Z,1741708387.462 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-03-11T15:53:07.859Z,1741708387.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-03-11T15:53:07.860Z,1741708387.860 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-03-11T15:53:07.972Z,1741708387.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-03-11T15:53:07.973Z,1741708387.973 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-03-11T15:53:08.455Z,1741708388.455 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-03-11T15:53:08.456Z,1741708388.456 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-03-11T15:53:08.719Z,1741708388.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-03-11T15:53:08.719Z,1741708388.719 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-03-11T15:53:09.313Z,1741708389.313 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-03-11T15:53:09.313Z,1741708389.313 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-03-11T15:53:09.488Z,1741708389.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-03-11T15:53:09.489Z,1741708389.489 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-03-11T15:53:09.759Z,1741708389.759 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-03-11T15:53:10.894Z,1741708390.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-03-11T15:53:10.895Z,1741708390.895 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-03-11T15:53:11.322Z,1741708391.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-03-11T15:53:11.323Z,1741708391.323 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-03-11T15:53:11.544Z,1741708391.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-03-11T15:53:11.545Z,1741708391.545 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-03-11T15:53:11.673Z,1741708391.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-03-11T15:53:11.674Z,1741708391.674 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-03-11T15:53:11.939Z,1741708391.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-03-11T15:53:11.940Z,1741708391.940 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-03-11T15:53:12.226Z,1741708392.226 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-03-11T15:53:12.228Z,1741708392.228 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2025-03-11T15:53:12.229Z,1741708392.229 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2025-03-11T15:53:12.330Z,1741708392.330 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2025-03-11T15:53:12.451Z,1741708392.451 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2025-03-11T15:53:12.548Z,1741708392.548 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2025-03-11T15:53:12.668Z,1741708392.668 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2025-03-11T15:53:12.776Z,1741708392.776 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2025-03-11T15:53:12.913Z,1741708392.913 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2025-03-11T15:53:13.094Z,1741708393.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2025-03-11T15:53:13.270Z,1741708393.270 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2025-03-11T15:53:13.401Z,1741708393.401 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2025-03-11T15:53:13.691Z,1741708393.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-03-11T15:53:13.692Z,1741708393.692 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2025-03-11T15:53:13.692Z,1741708393.692 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-03-11T15:53:13.701Z,1741708393.701 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-03-11T15:53:13.759Z,1741708393.759 [VerticalControl](DEBUG): Construct VerticalControl. 2025-03-11T15:53:13.825Z,1741708393.825 [VerticalControl] Loaded 2025-03-11T15:53:13.825Z,1741708393.825 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-03-11T15:53:13.828Z,1741708393.828 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-03-11T15:53:13.877Z,1741708393.877 [HorizontalControl] Loaded 2025-03-11T15:53:13.877Z,1741708393.877 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-03-11T15:53:13.880Z,1741708393.880 [SpeedControl](DEBUG): Construct SpeedControl. 2025-03-11T15:53:13.883Z,1741708393.883 [SpeedControl] Loaded 2025-03-11T15:53:13.883Z,1741708393.883 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-03-11T15:53:13.886Z,1741708393.886 [LoopControl](DEBUG): Construct LoopControl. 2025-03-11T15:53:13.887Z,1741708393.887 [LoopControl] Loaded 2025-03-11T15:53:13.887Z,1741708393.887 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-03-11T15:53:13.888Z,1741708393.888 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-03-11T15:53:13.888Z,1741708393.888 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-03-11T15:53:13.899Z,1741708393.899 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-03-11T15:53:13.900Z,1741708393.900 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-03-11T15:53:14.090Z,1741708394.090 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-03-11T15:53:14.091Z,1741708394.091 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-03-11T15:53:14.260Z,1741708394.260 [BuoyancyServo] Loaded 2025-03-11T15:53:14.260Z,1741708394.260 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-03-11T15:53:14.284Z,1741708394.284 [ElevatorServo] Loaded 2025-03-11T15:53:14.284Z,1741708394.284 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-03-11T15:53:14.306Z,1741708394.306 [MassServo] Loaded 2025-03-11T15:53:14.306Z,1741708394.306 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-03-11T15:53:14.327Z,1741708394.327 [RudderServo] Loaded 2025-03-11T15:53:14.328Z,1741708394.328 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-03-11T15:53:14.345Z,1741708394.345 [ThrusterHE] Loaded 2025-03-11T15:53:14.346Z,1741708394.346 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-03-11T15:53:14.346Z,1741708394.346 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-03-11T15:53:14.347Z,1741708394.347 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-03-11T15:53:14.467Z,1741708394.467 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-03-11T15:53:14.467Z,1741708394.467 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-03-11T15:53:14.481Z,1741708394.481 [NavChart] Loaded 2025-03-11T15:53:14.482Z,1741708394.482 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-03-11T15:53:14.488Z,1741708394.488 [UniversalFixResidualReporter] Loaded 2025-03-11T15:53:14.488Z,1741708394.488 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-03-11T15:53:14.488Z,1741708394.488 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-03-11T15:53:14.489Z,1741708394.489 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-03-11T15:53:14.721Z,1741708394.721 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-03-11T15:53:14.722Z,1741708394.722 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-03-11T15:53:15.736Z,1741708395.736 [AHRS_M2] Loaded 2025-03-11T15:53:15.736Z,1741708395.736 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-03-11T15:53:16.575Z,1741708396.575 [BPC1] Loaded 2025-03-11T15:53:16.575Z,1741708396.575 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-03-11T15:53:16.678Z,1741708396.678 [DAT] Loaded 2025-03-11T15:53:16.678Z,1741708396.678 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-03-11T15:53:16.679Z,1741708396.679 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4094B4E0 2025-03-11T15:53:16.680Z,1741708396.680 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1065 2025-03-11T15:53:16.754Z,1741708396.754 [DataOverHttps] Loaded 2025-03-11T15:53:16.754Z,1741708396.754 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-03-11T15:53:16.756Z,1741708396.756 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097B4E0 2025-03-11T15:53:16.756Z,1741708396.756 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1066 2025-03-11T15:53:16.780Z,1741708396.780 [Depth_Keller] Loaded 2025-03-11T15:53:16.780Z,1741708396.780 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-03-11T15:53:16.785Z,1741708396.785 [DropWeight] Loaded 2025-03-11T15:53:16.786Z,1741708396.786 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-03-11T15:53:16.853Z,1741708396.853 [NAL9602] Loaded 2025-03-11T15:53:16.853Z,1741708396.853 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-03-11T15:53:16.884Z,1741708396.884 [Onboard] Loaded 2025-03-11T15:53:16.884Z,1741708396.884 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-03-11T15:53:16.885Z,1741708396.885 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AB4E0 2025-03-11T15:53:16.886Z,1741708396.886 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1067 2025-03-11T15:53:16.900Z,1741708396.900 [Power24vConverter] Loaded 2025-03-11T15:53:16.901Z,1741708396.901 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-03-11T15:53:16.917Z,1741708396.917 [Radio_Surface] Loaded 2025-03-11T15:53:16.918Z,1741708396.918 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-03-11T15:53:16.919Z,1741708396.919 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0 2025-03-11T15:53:16.919Z,1741708396.919 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1068 2025-03-11T15:53:16.935Z,1741708396.935 [Sonardyne_Nano] Loaded 2025-03-11T15:53:16.935Z,1741708396.935 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-03-11T15:53:16.936Z,1741708396.936 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-03-11T15:53:16.936Z,1741708396.936 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-03-11T15:53:16.991Z,1741708396.991 [DepthRateCalculator] Loaded 2025-03-11T15:53:16.991Z,1741708396.991 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-03-11T15:53:16.996Z,1741708396.996 [PitchRateCalculator] Loaded 2025-03-11T15:53:16.997Z,1741708396.997 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-03-11T15:53:17.006Z,1741708397.006 [SpeedCalculator] Loaded 2025-03-11T15:53:17.006Z,1741708397.006 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-03-11T15:53:17.011Z,1741708397.011 [YawRateCalculator] Loaded 2025-03-11T15:53:17.011Z,1741708397.011 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-03-11T15:53:17.031Z,1741708397.031 [ElevatorOffsetCalculator] Loaded 2025-03-11T15:53:17.031Z,1741708397.031 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-03-11T15:53:17.032Z,1741708397.032 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-03-11T15:53:17.033Z,1741708397.033 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-03-11T15:53:17.169Z,1741708397.169 [CANONSampler] Loaded 2025-03-11T15:53:17.169Z,1741708397.169 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2025-03-11T15:53:17.236Z,1741708397.236 [CTD_Seabird] Loaded 2025-03-11T15:53:17.236Z,1741708397.236 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-03-11T15:53:17.237Z,1741708397.237 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A964E0 2025-03-11T15:53:17.238Z,1741708397.238 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1069 2025-03-11T15:53:17.261Z,1741708397.261 [PAR_Licor] Loaded 2025-03-11T15:53:17.261Z,1741708397.261 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-03-11T15:53:17.309Z,1741708397.309 [WetLabsBB2FL] Loaded 2025-03-11T15:53:17.310Z,1741708397.310 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-03-11T15:53:17.311Z,1741708397.311 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC64E0 2025-03-11T15:53:17.311Z,1741708397.311 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1070 2025-03-11T15:53:17.312Z,1741708397.312 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-03-11T15:53:17.313Z,1741708397.313 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-03-11T15:53:17.343Z,1741708397.343 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-03-11T15:53:17.344Z,1741708397.344 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-03-11T15:53:17.716Z,1741708397.716 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-03-11T15:53:17.717Z,1741708397.717 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-03-11T15:53:17.959Z,1741708397.959 [SBIT](DEBUG): Construct Startup Built In Test. 2025-03-11T15:53:17.969Z,1741708397.969 [SBIT] Loaded 2025-03-11T15:53:17.969Z,1741708397.969 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-03-11T15:53:17.972Z,1741708397.972 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-03-11T15:53:17.986Z,1741708397.986 [IBIT] Loaded 2025-03-11T15:53:17.986Z,1741708397.986 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-03-11T15:53:17.992Z,1741708397.992 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-03-11T15:53:18.079Z,1741708398.079 [CBIT] Loaded 2025-03-11T15:53:18.079Z,1741708398.079 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-03-11T15:53:18.113Z,1741708398.113 [GFScanner] Loaded 2025-03-11T15:53:18.113Z,1741708398.113 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-03-11T15:53:18.114Z,1741708398.114 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-03-11T15:53:18.114Z,1741708398.114 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-03-11T15:53:18.257Z,1741708398.257 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-03-11T15:53:18.264Z,1741708398.264 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-03-11T15:53:18.267Z,1741708398.267 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-03-11T15:53:18.279Z,1741708398.279 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-03-11T15:53:18.280Z,1741708398.280 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0 2025-03-11T15:53:18.280Z,1741708398.280 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1071 2025-03-11T15:53:18.285Z,1741708398.285 [Supervisor](INFO): Main Thread ID is 831 2025-03-11T15:53:18.285Z,1741708398.285 [Supervisor](DEBUG): Running supervisor. 2025-03-11T15:53:18.286Z,1741708398.286 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1072 2025-03-11T15:53:18.286Z,1741708398.286 [CommandExec](INFO): Initializing the command executive. 2025-03-11T15:53:18.288Z,1741708398.288 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1073 2025-03-11T15:53:18.290Z,1741708398.290 [controlThread ThreadHandler](INFO): Handler Thread ID is 1074 2025-03-11T15:53:18.290Z,1741708398.290 [controlThread](DEBUG): Initializing ControlThread 2025-03-11T15:53:18.291Z,1741708398.291 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-03-11T15:53:18.293Z,1741708398.293 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-03-11T15:53:18.294Z,1741708398.294 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-03-11T15:53:18.294Z,1741708398.294 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-03-11T15:53:18.296Z,1741708398.296 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-03-11T15:53:18.297Z,1741708398.297 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-03-11T15:53:18.302Z,1741708398.302 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-03-11T15:53:18.302Z,1741708398.302 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-03-11T15:53:18.302Z,1741708398.302 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-03-11T15:53:18.303Z,1741708398.303 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-03-11T15:53:18.303Z,1741708398.303 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-03-11T15:53:18.308Z,1741708398.308 [SBIT](INFO): Initialize SBIT Component. 2025-03-11T15:53:18.308Z,1741708398.308 [SBIT](IMPORTANT): git: 2025-03-10 2025-03-11T15:53:18.308Z,1741708398.308 [SBIT](INFO): git hash: ed984fb97dc40cbcfe09dec37ea56a9b8070d839 2025-03-11T15:53:18.309Z,1741708398.309 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-03-11T15:53:18.310Z,1741708398.310 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2025-03-11T15:53:18.311Z,1741708398.311 [SBIT](INFO): Beginning SBIT in 77.000000 seconds. 2025-03-11T15:53:18.312Z,1741708398.312 [IBIT](INFO): Initialize IBIT Component. 2025-03-11T15:53:18.313Z,1741708398.313 [CBIT](DEBUG): Initialize CBIT Component. 2025-03-11T15:53:18.313Z,1741708398.313 [logger ThreadHandler](INFO): Handler Thread ID is 1075 2025-03-11T15:53:18.324Z,1741708398.324 [CBIT](DEBUG): Initialized mux pins. 2025-03-11T15:53:18.324Z,1741708398.324 [CBIT](DEBUG): Initializing the watchdog timer. 2025-03-11T15:53:18.332Z,1741708398.332 [DAT ThreadHandler](INFO): Handler Thread ID is 1076 2025-03-11T15:53:18.333Z,1741708398.333 [DAT](INFO): Powering up 2025-03-11T15:53:18.333Z,1741708398.333 [DAT](DEBUG): Initializing DAT. 2025-03-11T15:53:18.337Z,1741708398.337 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1078 2025-03-11T15:53:18.339Z,1741708398.339 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-03-11T15:53:18.348Z,1741708398.348 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-03-11T15:53:18.348Z,1741708398.348 [CBIT](DEBUG): Initializing heartbeat. 2025-03-11T15:53:18.349Z,1741708398.349 [Onboard ThreadHandler](INFO): Handler Thread ID is 1079 2025-03-11T15:53:18.369Z,1741708398.369 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1080 2025-03-11T15:53:18.380Z,1741708398.380 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1081 2025-03-11T15:53:18.381Z,1741708398.381 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-03-11T15:53:18.385Z,1741708398.385 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1083 2025-03-11T15:53:18.389Z,1741708398.389 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1085 2025-03-11T15:53:18.392Z,1741708398.392 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-03-11T15:53:18.392Z,1741708398.392 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-03-11T15:53:18.392Z,1741708398.392 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-03-11T15:53:18.392Z,1741708398.392 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-03-11T15:53:18.393Z,1741708398.393 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-03-11T15:53:18.393Z,1741708398.393 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-03-11T15:53:18.393Z,1741708398.393 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-03-11T15:53:18.393Z,1741708398.393 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-03-11T15:53:18.408Z,1741708398.408 [WetLabsBB2FL](INFO): Powering up 2025-03-11T15:53:18.420Z,1741708398.420 [CBIT](DEBUG): Deactivating emergency mode. 2025-03-11T15:53:18.460Z,1741708398.460 [CBIT](DEBUG): Backplane powered. 2025-03-11T15:53:18.460Z,1741708398.460 [GFScanner](DEBUG): Initializing GFScanner 2025-03-11T15:53:18.460Z,1741708398.460 [GFScanner](DEBUG): Deactivating GF circuits. 2025-03-11T15:53:18.465Z,1741708398.465 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-03-11T15:53:18.465Z,1741708398.465 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-03-11T15:53:18.466Z,1741708398.466 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-03-11T15:53:18.467Z,1741708398.467 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-03-11T15:53:18.520Z,1741708398.520 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-03-11T15:53:18.540Z,1741708398.540 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-03-11T15:53:18.598Z,1741708398.598 [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-03-11T15:53:18.599Z,1741708398.599 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-03-11T15:53:18.599Z,1741708398.599 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-03-11T15:53:18.600Z,1741708398.600 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-03-11T15:53:18.772Z,1741708398.772 [Radio_Surface](INFO): Powering up 2025-03-11T15:53:18.929Z,1741708398.929 [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-03-11T15:53:18.958Z,1741708398.958 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-03-11T15:53:18.976Z,1741708398.976 [Default:A.Wait](DEBUG): Construct Wait. 2025-03-11T15:53:18.978Z,1741708398.978 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-03-11T15:53:18.998Z,1741708398.998 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-03-11T15:53:19.021Z,1741708399.021 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-03-11T15:53:19.027Z,1741708399.027 [Default:E.Execute](DEBUG): Construct Execute. 2025-03-11T15:53:19.046Z,1741708399.046 [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-03-11T15:53:19.051Z,1741708399.051 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,Reporter,LogSplitter, 2025-03-11T15:53:19.074Z,1741708399.074 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-03-11T15:53:19.142Z,1741708399.142 [Power24vConverter](INFO): Powering up. 2025-03-11T15:53:19.143Z,1741708399.143 [Sonardyne_Nano](INFO): Initializing. 2025-03-11T15:53:19.160Z,1741708399.160 [CANONSampler](INFO): Powering down 2025-03-11T15:53:19.334Z,1741708399.334 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-03-11T15:53:19.342Z,1741708399.342 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-03-11T15:53:19.343Z,1741708399.343 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-03-11T15:53:19.348Z,1741708399.348 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-03-11T15:53:19.349Z,1741708399.349 [MassServo](DEBUG): Initializing EZServoServo. 2025-03-11T15:53:19.356Z,1741708399.356 [MassServo](DEBUG): Initializing MassServo. 2025-03-11T15:53:19.357Z,1741708399.357 [RudderServo](DEBUG): Initializing EZServoServo. 2025-03-11T15:53:19.364Z,1741708399.364 [RudderServo](DEBUG): Initializing RudderServo. 2025-03-11T15:53:19.365Z,1741708399.365 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-03-11T15:53:19.372Z,1741708399.372 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-03-11T15:53:20.496Z,1741708400.496 [WetLabsBB2FL](INFO): Powering down 2025-03-11T15:53:21.078Z,1741708401.078 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-03-11T15:53:22.366Z,1741708402.366 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2025-03-11T15:53:25.045Z,1741708405.045 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-03-11T15:53:29.924Z,1741708409.924 [DAT](INFO): DAT read: 2025-03-11T15:53:29.926Z,1741708409.926 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-03-11T15:53:31.437Z,1741708411.437 [DAT](INFO): DAT read: MF Frequency Band 2025-03-11T15:53:31.438Z,1741708411.438 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-03-11T15:53:31.438Z,1741708411.438 [DAT](INFO): DAT read: Mar 11 2025 15:53:26 2025-03-11T15:53:32.697Z,1741708412.697 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-03-11T15:53:32.698Z,1741708412.698 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-03-11T15:53:32.698Z,1741708412.698 [DAT](INFO): commRate: 1200 2025-03-11T15:53:34.764Z,1741708414.764 [DAT](INFO): entering command mode 2025-03-11T15:53:34.964Z,1741708414.964 [DAT](INFO): DAT read: 2025-03-11T15:53:34.965Z,1741708414.965 [DAT](INFO): DAT read: user:1> 2025-03-11T15:53:34.965Z,1741708414.965 [DAT](INFO): setting verbose to 3 2025-03-11T15:53:35.216Z,1741708415.216 [DAT](INFO): DAT read: user:1> 2025-03-11T15:53:35.218Z,1741708415.218 [DAT](INFO): DAT read: Verbose | 3 2025-03-11T15:53:35.218Z,1741708415.218 [DAT](INFO): set verbose to 3 2025-03-11T15:53:35.218Z,1741708415.218 [DAT](INFO): setting DatVerbose to 27440 2025-03-11T15:53:35.469Z,1741708415.469 [DAT](INFO): DAT read: user:2> 2025-03-11T15:53:35.470Z,1741708415.470 [DAT](INFO): DAT read: DatVerbose | 27440 2025-03-11T15:53:35.470Z,1741708415.470 [DAT](INFO): set DatVerbose to 27440 2025-03-11T15:53:35.470Z,1741708415.470 [DAT](INFO): setting transmit power to 8 2025-03-11T15:53:35.720Z,1741708415.720 [DAT](INFO): DAT read: user:3> 2025-03-11T15:53:35.721Z,1741708415.721 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-03-11T15:53:35.722Z,1741708415.722 [DAT](INFO): set transmit power to 8 2025-03-11T15:53:35.722Z,1741708415.722 [DAT](INFO): setting local address to 8 2025-03-11T15:53:35.972Z,1741708415.972 [DAT](INFO): DAT read: user:4> 2025-03-11T15:53:35.973Z,1741708415.973 [DAT](INFO): DAT read: LocalAddr | 8 2025-03-11T15:53:35.974Z,1741708415.974 [DAT](INFO): set local address to 8 2025-03-11T15:53:35.975Z,1741708415.975 [DAT](INFO): Setting time to: 15:53:35 And date to:3/11/2025 2025-03-11T15:53:36.225Z,1741708416.225 [DAT](INFO): DAT read: user:5> 2025-03-11T15:53:36.225Z,1741708416.225 [DAT](INFO): DAT read: Tue Mar 11, 2025 15:53:35 2025-03-11T15:53:36.226Z,1741708416.226 [DAT](INFO): Local DAT time set to Tue Mar 11, 2025 15:53:35 2025-03-11T15:53:47.033Z,1741708427.033 [NAL9602](INFO): Powering up NAL9602 2025-03-11T15:53:57.937Z,1741708437.937 [NAL9602](INFO): NAL9602 initialized 2025-03-11T15:54:27.419Z,1741708467.419 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T15:54:35.930Z,1741708475.930 [SBIT](IMPORTANT): Beginning Startup BIT 2025-03-11T15:54:35.935Z,1741708475.935 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-03-11T15:54:40.428Z,1741708480.428 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.007906 CHAN A1 (24V): 0.000643 CHAN A2 (12V): -0.001938 CHAN A3 (5V): -0.001138 CHAN B0 (3.3V): -0.000224 CHAN B1 (3.15aV): 0.000089 CHAN B2 (3.15bV): -0.000123 CHAN B3 (GND): 0.000197 OPEN: -0.000391 Full Scale: +/- 1 mA 2025-03-11T15:54:46.809Z,1741708486.809 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T15:54:55.873Z,1741708495.873 [CommandExec](IMPORTANT): got command strobe off 2025-03-11T15:54:55.873Z,1741708495.873 [CommandExec](IMPORTANT): Deactivating strobe 2025-03-11T15:55:06.196Z,1741708506.196 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T15:55:25.998Z,1741708525.998 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T15:55:30.060Z,1741708530.060 [SBIT](IMPORTANT): SBIT PASSED 2025-03-11T15:55:30.060Z,1741708530.060 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-03-11T15:55:30.061Z,1741708530.061 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=11 count; 2025-03-11T15:55:30.062Z,1741708530.062 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter; 2025-03-11T15:55:30.062Z,1741708530.062 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter; 2025-03-11T15:55:30.062Z,1741708530.062 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool; 2025-03-11T15:55:30.062Z,1741708530.062 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool; 2025-03-11T15:55:30.064Z,1741708530.064 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=162.399981 cubic_centimeter; 2025-03-11T15:55:30.064Z,1741708530.064 [SBIT](IMPORTANT): VerticalControl.massDefault=14.329862 millimeter; 2025-03-11T15:55:30.478Z,1741708530.478 [MissionManager](IMPORTANT): Started mission Startup 2025-03-11T15:55:30.478Z,1741708530.478 [Startup] Running Loop=1 2025-03-11T15:55:30.478Z,1741708530.478 [Startup](DEBUG): Aggregate::initialize Startup 2025-03-11T15:55:30.478Z,1741708530.478 [Startup:A.GoToSurface] Running Loop=1 2025-03-11T15:55:30.478Z,1741708530.478 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-03-11T15:55:30.479Z,1741708530.479 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-03-11T15:55:30.480Z,1741708530.480 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-03-11T15:55:30.480Z,1741708530.480 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-03-11T15:55:30.481Z,1741708530.481 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-03-11T15:55:30.481Z,1741708530.481 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-03-11T15:55:30.481Z,1741708530.481 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-03-11T15:55:30.483Z,1741708530.483 [Startup:StartupSatComms] Running Loop=1 2025-03-11T15:55:30.483Z,1741708530.483 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-03-11T15:55:30.484Z,1741708530.484 [Startup:StartupSatComms:A] Running Loop=1 2025-03-11T15:55:30.889Z,1741708530.889 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-03-11T15:55:44.985Z,1741708544.985 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T15:56:01.374Z,1741708561.374 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004633 2025-03-11T15:56:18.558Z,1741708578.558 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-03-11T15:56:18.558Z,1741708578.558 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T15:56:18.585Z,1741708578.585 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T15:56:18.960Z,1741708578.960 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T15:56:18.960Z,1741708578.960 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-03-11T15:56:30.662Z,1741708590.662 [Startup:StartupSatComms:A](INFO): Timed out from 2025-03-11T15:55:30.5Z 2025-03-11T15:56:30.662Z,1741708590.662 [Startup:StartupSatComms:A] Stopped 2025-03-11T15:56:30.662Z,1741708590.662 [Startup:StartupSatComms:B] Running Loop=1 2025-03-11T15:56:31.058Z,1741708591.058 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-03-11T15:56:35.971Z,1741708595.971 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-11T15:56:36.391Z,1741708596.391 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-03-11T15:56:39.185Z,1741708599.185 [DataOverHttps](INFO): Sending 185 bytes from file Logs/20250311T154251/Courier0000.lzma 2025-03-11T15:56:40.186Z,1741708600.186 [DataOverHttps](INFO): Moved sent file to Logs/20250311T154251/Courier0000.lzma.bak 2025-03-11T15:56:40.186Z,1741708600.186 [DataOverHttps](INFO): SBD MOMSN=24175386 2025-03-11T15:56:56.021Z,1741708616.021 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250311T154546/Courier0000.lzma 2025-03-11T15:56:57.021Z,1741708617.021 [DataOverHttps](INFO): Moved sent file to Logs/20250311T154546/Courier0000.lzma.bak 2025-03-11T15:56:57.022Z,1741708617.022 [DataOverHttps](INFO): SBD MOMSN=24175393 2025-03-11T15:57:12.696Z,1741708632.696 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250311T154945/Courier0000.lzma 2025-03-11T15:57:13.698Z,1741708633.698 [DataOverHttps](INFO): Moved sent file to Logs/20250311T154945/Courier0000.lzma.bak 2025-03-11T15:57:13.698Z,1741708633.698 [DataOverHttps](INFO): SBD MOMSN=24175399 2025-03-11T15:57:29.796Z,1741708649.796 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250311T155306/Courier0000.lzma 2025-03-11T15:57:30.496Z,1741708650.496 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-03-11T15:57:30.797Z,1741708650.797 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0000.lzma.bak 2025-03-11T15:57:30.798Z,1741708650.798 [DataOverHttps](INFO): SBD MOMSN=24175402 2025-03-11T15:57:30.878Z,1741708650.878 [Startup:StartupSatComms:B](INFO): Timed out from 2025-03-11T15:56:30.7Z 2025-03-11T15:57:30.878Z,1741708650.878 [Startup:StartupSatComms:B] Stopped 2025-03-11T15:57:30.878Z,1741708650.878 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-03-11T15:57:30.878Z,1741708650.878 [Startup:StartupSatComms] Stopped 2025-03-11T15:57:30.878Z,1741708650.878 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-03-11T15:57:30.879Z,1741708650.879 [Startup](INFO): Completed Startup 2025-03-11T15:57:30.879Z,1741708650.879 [MissionManager](INFO): Startup is completed. 2025-03-11T15:57:30.880Z,1741708650.880 [MissionManager](INFO): Uninitializing Mission Startup 2025-03-11T15:57:30.880Z,1741708650.880 [Startup] Stopped 2025-03-11T15:57:30.880Z,1741708650.880 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-03-11T15:57:30.880Z,1741708650.880 [Startup:A.GoToSurface] Stopped 2025-03-11T15:57:30.880Z,1741708650.880 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-03-11T15:57:31.274Z,1741708651.274 [MissionManager](IMPORTANT): Started mission Default 2025-03-11T15:57:31.274Z,1741708651.274 [Default] Running Loop=1 2025-03-11T15:57:31.275Z,1741708651.275 [Default](DEBUG): Aggregate::initialize Default 2025-03-11T15:57:31.275Z,1741708651.275 [Default:B.GoToSurface] Running Loop=1 2025-03-11T15:57:31.275Z,1741708651.275 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-03-11T15:57:31.275Z,1741708651.275 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-03-11T15:57:31.275Z,1741708651.275 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-03-11T15:57:31.276Z,1741708651.276 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-03-11T15:57:31.276Z,1741708651.276 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-03-11T15:57:31.277Z,1741708651.277 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-03-11T15:57:31.277Z,1741708651.277 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-03-11T15:57:31.277Z,1741708651.277 [Default:A.Wait] Running Loop=1 2025-03-11T15:57:31.277Z,1741708651.277 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-03-11T15:57:44.615Z,1741708664.615 [Default:A.Wait](INFO): Done Waiting. 2025-03-11T15:57:44.615Z,1741708664.615 [Default:A.Wait] Stopped 2025-03-11T15:57:44.615Z,1741708664.615 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T15:57:44.994Z,1741708664.994 [Default:CheckIn] Running Loop=1 2025-03-11T15:57:44.994Z,1741708664.994 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T15:57:44.994Z,1741708664.994 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T15:57:45.401Z,1741708665.401 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-03-11T15:57:49.074Z,1741708669.074 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-11T15:58:48.544Z,1741708728.544 [CommandExec](IMPORTANT): got command failComponent 2025-03-11T15:58:48.545Z,1741708728.545 [CommandExec](IMPORTANT): Failed components: 2025-03-11T15:58:48.545Z,1741708728.545 [CommandExec](IMPORTANT): No failed Components. 2025-03-11T15:58:51.361Z,1741708731.361 [CommandExec](IMPORTANT): got command failComponent 2025-03-11T15:58:51.361Z,1741708731.361 [CommandExec](IMPORTANT): Failed components: 2025-03-11T15:58:51.361Z,1741708731.361 [CommandExec](IMPORTANT): No failed Components. 2025-03-11T15:59:01.745Z,1741708741.745 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-03-11T15:59:05.489Z,1741708745.489 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-03-11T15:59:19.577Z,1741708759.577 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-03-11T15:59:19.577Z,1741708759.577 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T15:59:19.588Z,1741708759.588 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T15:59:19.958Z,1741708759.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T15:59:19.958Z,1741708759.958 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-03-11T16:00:25.865Z,1741708825.865 [CommandExec](IMPORTANT): got command burn on 2025-03-11T16:00:25.865Z,1741708825.865 [CommandExec](IMPORTANT): Activating dropweight wire 2025-03-11T16:00:43.150Z,1741708843.150 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 4. 2025-03-11T16:00:43.165Z,1741708843.165 [BPC1](INFO): Received data from all battery sticks. 2025-03-11T16:02:20.549Z,1741708940.549 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-03-11T16:02:20.549Z,1741708940.549 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:02:20.560Z,1741708940.560 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:02:20.965Z,1741708940.965 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:02:20.965Z,1741708940.965 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-03-11T16:02:45.165Z,1741708965.165 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-11T15:57:44.0Z 2025-03-11T16:02:45.165Z,1741708965.165 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:02:45.166Z,1741708965.166 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:02:45.578Z,1741708965.578 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-03-11T16:02:52.564Z,1741708972.564 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250311T155306/Courier0004.lzma 2025-03-11T16:02:53.565Z,1741708973.565 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0004.lzma.bak 2025-03-11T16:02:53.566Z,1741708973.566 [DataOverHttps](INFO): SBD MOMSN=24175687 2025-03-11T16:03:01.557Z,1741708981.557 [CommandExec](IMPORTANT): got command burn off 2025-03-11T16:03:01.557Z,1741708981.557 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-03-11T16:03:09.070Z,1741708989.070 [DataOverHttps](INFO): Sending 973 bytes from file Logs/20250311T154251/Express0001.lzma 2025-03-11T16:03:10.069Z,1741708990.069 [DataOverHttps](INFO): Moved sent file to Logs/20250311T154251/Express0001.lzma.bak 2025-03-11T16:03:10.070Z,1741708990.070 [DataOverHttps](INFO): SBD MOMSN=24175689 2025-03-11T16:03:25.846Z,1741709005.846 [DataOverHttps](INFO): Sending 963 bytes from file Logs/20250311T154546/Express0001.lzma 2025-03-11T16:03:26.845Z,1741709006.845 [DataOverHttps](INFO): Moved sent file to Logs/20250311T154546/Express0001.lzma.bak 2025-03-11T16:03:26.846Z,1741709006.846 [DataOverHttps](INFO): SBD MOMSN=24175712 2025-03-11T16:03:42.390Z,1741709022.390 [DataOverHttps](INFO): Sending 934 bytes from file Logs/20250311T154945/Express0001.lzma 2025-03-11T16:03:43.389Z,1741709023.389 [DataOverHttps](INFO): Moved sent file to Logs/20250311T154945/Express0001.lzma.bak 2025-03-11T16:03:43.390Z,1741709023.390 [DataOverHttps](INFO): SBD MOMSN=24175738 2025-03-11T16:03:59.102Z,1741709039.102 [DataOverHttps](INFO): Sending 917 bytes from file Logs/20250311T155306/Express0001.lzma 2025-03-11T16:03:59.899Z,1741709039.899 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-11T16:03:59.900Z,1741709039.900 [NAL9602] Data Fault, FailCount= 1 2025-03-11T16:03:59.900Z,1741709039.900 [NAL9602](ERROR): Data Fault 2025-03-11T16:03:59.917Z,1741709039.917 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-11T16:04:00.102Z,1741709040.102 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0001.lzma.bak 2025-03-11T16:04:00.102Z,1741709040.102 [DataOverHttps](INFO): SBD MOMSN=24175760 2025-03-11T16:04:00.301Z,1741709040.301 [NAL9602](INFO): Powering down 2025-03-11T16:04:01.134Z,1741709041.134 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-11T16:04:01.134Z,1741709041.134 [NAL9602] No Fault, FailCount= 1 2025-03-11T16:04:15.660Z,1741709055.660 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20250311T155306/Express0005.lzma 2025-03-11T16:04:16.666Z,1741709056.666 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0005.lzma.bak 2025-03-11T16:04:16.666Z,1741709056.666 [DataOverHttps](INFO): SBD MOMSN=24175782 2025-03-11T16:04:17.716Z,1741709057.716 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:04:17.716Z,1741709057.716 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:04:17.717Z,1741709057.717 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:04:30.601Z,1741709070.601 [NAL9602](INFO): Powering up NAL9602 2025-03-11T16:04:41.506Z,1741709081.506 [NAL9602](INFO): NAL9602 initialized 2025-03-11T16:05:21.567Z,1741709121.567 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-03-11T16:05:21.567Z,1741709121.567 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:05:21.618Z,1741709121.618 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:05:22.005Z,1741709122.005 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:05:22.005Z,1741709122.005 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-03-11T16:07:51.333Z,1741709271.333 [CommandExec](IMPORTANT): got command burn off 2025-03-11T16:07:51.333Z,1741709271.333 [CommandExec](IMPORTANT): Deactivating dropweight wire 2025-03-11T16:08:22.605Z,1741709302.605 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-03-11T16:08:22.605Z,1741709302.605 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:08:22.624Z,1741709302.624 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:08:23.051Z,1741709303.051 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:08:23.051Z,1741709303.051 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-03-11T16:09:18.374Z,1741709358.374 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T16:09:18.374Z,1741709358.374 [Default:CheckIn:C.Wait] Stopped 2025-03-11T16:09:18.374Z,1741709358.374 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T16:09:18.374Z,1741709358.374 [Default:CheckIn:D] Running Loop=1 2025-03-11T16:09:18.767Z,1741709358.767 [Default:CheckIn:D] Stopped 2025-03-11T16:09:18.767Z,1741709358.767 [Default:CheckIn:E] Running Loop=1 2025-03-11T16:09:19.189Z,1741709359.189 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.791535 min 2025-03-11T16:09:19.189Z,1741709359.189 [Default:CheckIn:E] Stopped 2025-03-11T16:09:19.189Z,1741709359.189 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T16:09:19.189Z,1741709359.189 [Default:CheckIn] Stopped 2025-03-11T16:09:19.189Z,1741709359.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T16:09:19.189Z,1741709359.189 [Default:CheckIn](INFO): Running loop #2 2025-03-11T16:09:19.189Z,1741709359.189 [Default:CheckIn] Running Loop=2 2025-03-11T16:09:19.190Z,1741709359.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T16:09:19.190Z,1741709359.190 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T16:11:23.597Z,1741709483.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-03-11T16:11:23.597Z,1741709483.597 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:11:23.608Z,1741709483.608 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:11:24.016Z,1741709484.016 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:11:24.016Z,1741709484.016 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-03-11T16:12:08.992Z,1741709528.992 [CommandExec](IMPORTANT): got command failComponent 2025-03-11T16:12:08.992Z,1741709528.992 [CommandExec](IMPORTANT): Failed components: 2025-03-11T16:12:08.993Z,1741709528.993 [CommandExec](IMPORTANT): No failed Components. 2025-03-11T16:14:19.342Z,1741709659.342 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-11T16:09:19.2Z 2025-03-11T16:14:19.342Z,1741709659.342 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:14:19.342Z,1741709659.342 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:14:24.746Z,1741709664.746 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2025-03-11T16:14:24.746Z,1741709664.746 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:14:24.821Z,1741709664.821 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:14:25.229Z,1741709665.229 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:14:25.229Z,1741709665.229 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2025-03-11T16:14:28.712Z,1741709668.712 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250311T155306/Courier0007.lzma 2025-03-11T16:14:29.709Z,1741709669.709 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0007.lzma.bak 2025-03-11T16:14:29.710Z,1741709669.710 [DataOverHttps](INFO): SBD MOMSN=24176079 2025-03-11T16:14:43.322Z,1741709683.322 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-11T16:14:43.322Z,1741709683.322 [NAL9602] Data Fault, FailCount= 2 2025-03-11T16:14:43.322Z,1741709683.322 [NAL9602](ERROR): Data Fault 2025-03-11T16:14:43.359Z,1741709683.359 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-11T16:14:43.717Z,1741709683.717 [NAL9602](INFO): Powering down 2025-03-11T16:14:44.553Z,1741709684.553 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-11T16:14:44.553Z,1741709684.553 [NAL9602] No Fault, FailCount= 2 2025-03-11T16:14:45.284Z,1741709685.284 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20250311T155306/Express0008.lzma 2025-03-11T16:14:46.286Z,1741709686.286 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0008.lzma.bak 2025-03-11T16:14:46.286Z,1741709686.286 [DataOverHttps](INFO): SBD MOMSN=24176081 2025-03-11T16:14:47.373Z,1741709687.373 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:14:47.373Z,1741709687.373 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:14:47.373Z,1741709687.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:15:14.069Z,1741709714.069 [NAL9602](INFO): Powering up NAL9602 2025-03-11T16:15:24.981Z,1741709724.981 [NAL9602](INFO): NAL9602 initialized 2025-03-11T16:17:25.879Z,1741709845.879 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2025-03-11T16:17:25.879Z,1741709845.879 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:17:25.889Z,1741709845.889 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:17:26.310Z,1741709846.310 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:17:26.310Z,1741709846.310 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2025-03-11T16:19:48.097Z,1741709988.097 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T16:19:48.097Z,1741709988.097 [Default:CheckIn:C.Wait] Stopped 2025-03-11T16:19:48.097Z,1741709988.097 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T16:19:48.097Z,1741709988.097 [Default:CheckIn:D] Running Loop=1 2025-03-11T16:19:48.504Z,1741709988.504 [Default:CheckIn:D] Stopped 2025-03-11T16:19:48.504Z,1741709988.504 [Default:CheckIn:E] Running Loop=1 2025-03-11T16:19:48.901Z,1741709988.901 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.287162 min 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn:E] Stopped 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn] Stopped 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn](INFO): Running loop #3 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn] Running Loop=3 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T16:19:48.902Z,1741709988.902 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T16:20:26.896Z,1741710026.896 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2025-03-11T16:20:26.896Z,1741710026.896 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:20:26.911Z,1741710026.911 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:20:27.318Z,1741710027.318 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:20:27.318Z,1741710027.318 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2025-03-11T16:23:27.888Z,1741710207.888 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2025-03-11T16:23:27.888Z,1741710207.888 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:23:27.943Z,1741710207.943 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:23:28.334Z,1741710208.334 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:23:28.334Z,1741710208.334 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2025-03-11T16:24:49.070Z,1741710289.070 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-11T16:19:48.9Z 2025-03-11T16:24:49.070Z,1741710289.070 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:24:49.070Z,1741710289.070 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:24:59.283Z,1741710299.283 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250311T155306/Courier0010.lzma 2025-03-11T16:25:01.290Z,1741710301.290 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0010.lzma.bak 2025-03-11T16:25:01.290Z,1741710301.290 [DataOverHttps](INFO): SBD MOMSN=24176376 2025-03-11T16:25:16.858Z,1741710316.858 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250311T155306/Express0011.lzma 2025-03-11T16:25:17.994Z,1741710317.994 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0011.lzma.bak 2025-03-11T16:25:17.994Z,1741710317.994 [DataOverHttps](INFO): SBD MOMSN=24176378 2025-03-11T16:25:19.001Z,1741710319.001 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:25:19.001Z,1741710319.001 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:25:19.001Z,1741710319.001 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:25:25.856Z,1741710325.856 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-11T16:25:25.856Z,1741710325.856 [NAL9602] Data Fault, FailCount= 3 2025-03-11T16:25:25.856Z,1741710325.856 [NAL9602](ERROR): Data Fault 2025-03-11T16:25:25.873Z,1741710325.873 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-11T16:25:26.265Z,1741710326.265 [NAL9602](INFO): Powering down 2025-03-11T16:25:27.090Z,1741710327.090 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-11T16:25:27.090Z,1741710327.090 [NAL9602] No Fault, FailCount= 3 2025-03-11T16:25:56.565Z,1741710356.565 [NAL9602](INFO): Powering up NAL9602 2025-03-11T16:26:07.470Z,1741710367.470 [NAL9602](INFO): NAL9602 initialized 2025-03-11T16:26:28.988Z,1741710388.988 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2025-03-11T16:26:28.988Z,1741710388.988 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:26:29.037Z,1741710389.037 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:26:29.392Z,1741710389.392 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:26:29.392Z,1741710389.392 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2025-03-11T16:29:29.998Z,1741710569.998 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2025-03-11T16:29:29.998Z,1741710569.998 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:29:30.009Z,1741710570.009 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:29:30.422Z,1741710570.422 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:29:30.422Z,1741710570.422 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2025-03-11T16:30:19.696Z,1741710619.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T16:30:19.696Z,1741710619.696 [Default:CheckIn:C.Wait] Stopped 2025-03-11T16:30:19.696Z,1741710619.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T16:30:19.696Z,1741710619.696 [Default:CheckIn:D] Running Loop=1 2025-03-11T16:30:20.114Z,1741710620.114 [Default:CheckIn:D] Stopped 2025-03-11T16:30:20.114Z,1741710620.114 [Default:CheckIn:E] Running Loop=1 2025-03-11T16:30:20.502Z,1741710620.502 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.813989 min 2025-03-11T16:30:20.502Z,1741710620.502 [Default:CheckIn:E] Stopped 2025-03-11T16:30:20.502Z,1741710620.502 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T16:30:20.502Z,1741710620.502 [Default:CheckIn] Stopped 2025-03-11T16:30:20.503Z,1741710620.503 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T16:30:20.503Z,1741710620.503 [Default:CheckIn](INFO): Running loop #4 2025-03-11T16:30:20.503Z,1741710620.503 [Default:CheckIn] Running Loop=4 2025-03-11T16:30:20.503Z,1741710620.503 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T16:30:20.503Z,1741710620.503 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T16:32:31.014Z,1741710751.014 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2025-03-11T16:32:31.014Z,1741710751.014 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:32:31.025Z,1741710751.025 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:32:31.426Z,1741710751.426 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:32:31.426Z,1741710751.426 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2025-03-11T16:35:20.673Z,1741710920.673 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-11T16:30:20.5Z 2025-03-11T16:35:20.673Z,1741710920.673 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:35:20.673Z,1741710920.673 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:35:28.219Z,1741710928.219 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250311T155306/Courier0013.lzma 2025-03-11T16:35:29.222Z,1741710929.222 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0013.lzma.bak 2025-03-11T16:35:29.222Z,1741710929.222 [DataOverHttps](INFO): SBD MOMSN=24176725 2025-03-11T16:35:32.009Z,1741710932.009 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2025-03-11T16:35:32.009Z,1741710932.009 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-11T16:35:32.020Z,1741710932.020 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-11T16:35:32.435Z,1741710932.435 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-11T16:35:32.435Z,1741710932.435 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2025-03-11T16:35:44.796Z,1741710944.796 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250311T155306/Express0014.lzma 2025-03-11T16:35:45.798Z,1741710945.798 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0014.lzma.bak 2025-03-11T16:35:45.798Z,1741710945.798 [DataOverHttps](INFO): SBD MOMSN=24176727 2025-03-11T16:35:46.974Z,1741710946.974 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:35:46.974Z,1741710946.974 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:35:46.974Z,1741710946.974 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:35:49.755Z,1741710949.755 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163549.00,A,3648.18977,N,12147.28620,W,0.680,351.84,110325,,,A*77 2025-03-11T16:35:49.758Z,1741710949.758 [NAL9602](INFO): GPS fix at 20250311T163549: (36.803163, -121.788103) 2025-03-11T16:36:22.561Z,1741710982.561 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T16:38:26.308Z,1741711106.308 [CommandExec](IMPORTANT): got command failComponent 2025-03-11T16:38:26.308Z,1741711106.308 [CommandExec](IMPORTANT): Failed components: 2025-03-11T16:38:26.309Z,1741711106.309 [CommandExec](IMPORTANT): No failed Components. 2025-03-11T16:40:47.388Z,1741711247.388 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T16:40:47.388Z,1741711247.388 [Default:CheckIn:C.Wait] Stopped 2025-03-11T16:40:47.389Z,1741711247.389 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T16:40:47.389Z,1741711247.389 [Default:CheckIn:D] Running Loop=1 2025-03-11T16:40:47.807Z,1741711247.807 [Default:CheckIn:D] Stopped 2025-03-11T16:40:47.807Z,1741711247.807 [Default:CheckIn:E] Running Loop=1 2025-03-11T16:40:48.191Z,1741711248.191 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.275541 min 2025-03-11T16:40:48.191Z,1741711248.191 [Default:CheckIn:E] Stopped 2025-03-11T16:40:48.192Z,1741711248.192 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T16:40:48.192Z,1741711248.192 [Default:CheckIn] Stopped 2025-03-11T16:40:48.192Z,1741711248.192 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T16:40:48.192Z,1741711248.192 [Default:CheckIn](INFO): Running loop #5 2025-03-11T16:40:48.192Z,1741711248.192 [Default:CheckIn] Running Loop=5 2025-03-11T16:40:48.192Z,1741711248.192 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T16:40:48.192Z,1741711248.192 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T16:40:50.195Z,1741711250.195 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164049.00,A,3648.16807,N,12147.28704,W,0.952,351.84,110325,,,A*7A 2025-03-11T16:40:50.197Z,1741711250.197 [NAL9602](INFO): GPS fix at 20250311T164049: (36.802801, -121.788117) 2025-03-11T16:40:50.217Z,1741711250.217 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:40:50.217Z,1741711250.217 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:41:00.388Z,1741711260.388 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20250311T155306/Courier0016.lzma 2025-03-11T16:41:01.390Z,1741711261.390 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0016.lzma.bak 2025-03-11T16:41:01.390Z,1741711261.390 [DataOverHttps](INFO): SBD MOMSN=24176737 2025-03-11T16:41:17.324Z,1741711277.324 [DataOverHttps](INFO): Sending 424 bytes from file Logs/20250311T155306/Express0017.lzma 2025-03-11T16:41:18.326Z,1741711278.326 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0017.lzma.bak 2025-03-11T16:41:18.326Z,1741711278.326 [DataOverHttps](INFO): SBD MOMSN=24176740 2025-03-11T16:41:19.518Z,1741711279.518 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:41:19.518Z,1741711279.518 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:41:19.518Z,1741711279.518 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:41:25.962Z,1741711285.962 [NAL9602](INFO): SBD MO Status=2, MOMSN=62128, MT Status=2, MTMSN=0 2025-03-11T16:41:25.963Z,1741711285.963 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T16:41:43.345Z,1741711303.345 [NAL9602](INFO): SBD MO Status=2, MOMSN=62128, MT Status=2, MTMSN=0 2025-03-11T16:41:43.345Z,1741711303.345 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T16:42:15.250Z,1741711335.250 [NAL9602](INFO): SBD MO Status=2, MOMSN=62128, MT Status=2, MTMSN=0 2025-03-11T16:42:15.251Z,1741711335.251 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T16:45:52.309Z,1741711552.309 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-03-11T16:46:20.214Z,1741711580.214 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T16:46:20.214Z,1741711580.214 [Default:CheckIn:C.Wait] Stopped 2025-03-11T16:46:20.215Z,1741711580.215 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T16:46:20.215Z,1741711580.215 [Default:CheckIn:D] Running Loop=1 2025-03-11T16:46:20.607Z,1741711580.607 [Default:CheckIn:D] Stopped 2025-03-11T16:46:20.607Z,1741711580.607 [Default:CheckIn:E] Running Loop=1 2025-03-11T16:46:21.021Z,1741711581.021 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.822209 min 2025-03-11T16:46:21.021Z,1741711581.021 [Default:CheckIn:E] Stopped 2025-03-11T16:46:21.021Z,1741711581.021 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T16:46:21.021Z,1741711581.021 [Default:CheckIn] Stopped 2025-03-11T16:46:21.021Z,1741711581.021 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T16:46:21.021Z,1741711581.021 [Default:CheckIn](INFO): Running loop #6 2025-03-11T16:46:21.021Z,1741711581.021 [Default:CheckIn] Running Loop=6 2025-03-11T16:46:21.022Z,1741711581.022 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T16:46:21.022Z,1741711581.022 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T16:46:23.015Z,1741711583.015 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164622.00,A,3648.16162,N,12147.28746,W,0.097,78.88,110325,,,A*49 2025-03-11T16:46:23.017Z,1741711583.017 [NAL9602](INFO): GPS fix at 20250311T164622: (36.802694, -121.788124) 2025-03-11T16:46:23.056Z,1741711583.056 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:46:23.056Z,1741711583.056 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:46:31.215Z,1741711591.215 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0019.lzma 2025-03-11T16:46:32.217Z,1741711592.217 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0019.lzma.bak 2025-03-11T16:46:32.218Z,1741711592.218 [DataOverHttps](INFO): SBD MOMSN=24177025 2025-03-11T16:46:48.233Z,1741711608.233 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20250311T155306/Express0020.lzma 2025-03-11T16:46:49.234Z,1741711609.234 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0020.lzma.bak 2025-03-11T16:46:49.234Z,1741711609.234 [DataOverHttps](INFO): SBD MOMSN=24177028 2025-03-11T16:46:50.498Z,1741711610.498 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:46:50.498Z,1741711610.498 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:46:50.498Z,1741711610.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:46:55.385Z,1741711615.385 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T16:51:51.181Z,1741711911.181 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T16:51:51.181Z,1741711911.181 [Default:CheckIn:C.Wait] Stopped 2025-03-11T16:51:51.181Z,1741711911.181 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T16:51:51.181Z,1741711911.181 [Default:CheckIn:D] Running Loop=1 2025-03-11T16:51:51.592Z,1741711911.592 [Default:CheckIn:D] Stopped 2025-03-11T16:51:51.592Z,1741711911.592 [Default:CheckIn:E] Running Loop=1 2025-03-11T16:51:52.012Z,1741711912.012 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.338631 min 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn:E] Stopped 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn] Stopped 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn](INFO): Running loop #7 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn] Running Loop=7 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T16:51:52.013Z,1741711912.013 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T16:51:53.999Z,1741711913.999 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165153.00,A,3648.16487,N,12147.28613,W,0.292,89.01,110325,,,A*4E 2025-03-11T16:51:54.001Z,1741711914.001 [NAL9602](INFO): GPS fix at 20250311T165153: (36.802748, -121.788102) 2025-03-11T16:51:54.017Z,1741711914.017 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:51:54.017Z,1741711914.017 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:52:01.127Z,1741711921.127 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0022.lzma 2025-03-11T16:52:02.130Z,1741711922.130 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0022.lzma.bak 2025-03-11T16:52:02.130Z,1741711922.130 [DataOverHttps](INFO): SBD MOMSN=24177042 2025-03-11T16:52:18.345Z,1741711938.345 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250311T155306/Express0023.lzma 2025-03-11T16:52:19.346Z,1741711939.346 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0023.lzma.bak 2025-03-11T16:52:19.346Z,1741711939.346 [DataOverHttps](INFO): SBD MOMSN=24177045 2025-03-11T16:52:20.696Z,1741711940.696 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:52:20.696Z,1741711940.696 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:52:20.697Z,1741711940.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:52:24.745Z,1741711944.745 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-03-11T16:52:24.828Z,1741711944.828 [NAL9602](ERROR): received: +CSQ:0 OK128, 2, 0, 0, 0 OK 2025-03-11T16:56:30.835Z,1741712190.835 [NAL9602](INFO): SBD MO Status=2, MOMSN=62128, MT Status=2, MTMSN=0 2025-03-11T16:56:30.835Z,1741712190.835 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T16:56:47.806Z,1741712207.806 [NAL9602](INFO): SBD MO Status=2, MOMSN=62128, MT Status=2, MTMSN=0 2025-03-11T16:56:47.807Z,1741712207.807 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T16:57:05.176Z,1741712225.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=62128, MT Status=2, MTMSN=0 2025-03-11T16:57:05.177Z,1741712225.177 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T16:57:05.577Z,1741712225.577 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-03-11T16:57:21.344Z,1741712241.344 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T16:57:21.345Z,1741712241.345 [Default:CheckIn:C.Wait] Stopped 2025-03-11T16:57:21.345Z,1741712241.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T16:57:21.345Z,1741712241.345 [Default:CheckIn:D] Running Loop=1 2025-03-11T16:57:21.823Z,1741712241.823 [Default:CheckIn:D] Stopped 2025-03-11T16:57:21.823Z,1741712241.823 [Default:CheckIn:E] Running Loop=1 2025-03-11T16:57:22.151Z,1741712242.151 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.842476 min 2025-03-11T16:57:22.151Z,1741712242.151 [Default:CheckIn:E] Stopped 2025-03-11T16:57:22.151Z,1741712242.151 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T16:57:22.151Z,1741712242.151 [Default:CheckIn] Stopped 2025-03-11T16:57:22.168Z,1741712242.168 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T16:57:22.168Z,1741712242.168 [Default:CheckIn](INFO): Running loop #8 2025-03-11T16:57:22.168Z,1741712242.168 [Default:CheckIn] Running Loop=8 2025-03-11T16:57:22.168Z,1741712242.168 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T16:57:22.168Z,1741712242.168 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T16:57:24.167Z,1741712244.167 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165723.00,A,3648.16130,N,12147.28698,W,0.311,89.01,110325,,,A*4F 2025-03-11T16:57:24.169Z,1741712244.169 [NAL9602](INFO): GPS fix at 20250311T165723: (36.802688, -121.788116) 2025-03-11T16:57:24.180Z,1741712244.180 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T16:57:24.180Z,1741712244.180 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T16:57:31.943Z,1741712251.943 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0025.lzma 2025-03-11T16:57:32.946Z,1741712252.946 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0025.lzma.bak 2025-03-11T16:57:32.946Z,1741712252.946 [DataOverHttps](INFO): SBD MOMSN=24177355 2025-03-11T16:57:48.976Z,1741712268.976 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250311T155306/Express0026.lzma 2025-03-11T16:57:49.977Z,1741712269.977 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0026.lzma.bak 2025-03-11T16:57:49.978Z,1741712269.978 [DataOverHttps](INFO): SBD MOMSN=24177358 2025-03-11T16:57:51.243Z,1741712271.243 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T16:57:51.243Z,1741712271.243 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T16:57:51.243Z,1741712271.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T16:57:56.481Z,1741712276.481 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:01:49.235Z,1741712509.235 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:02:01.760Z,1741712521.760 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:02:13.477Z,1741712533.477 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:02:25.595Z,1741712545.595 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:02:37.718Z,1741712557.718 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:02:49.433Z,1741712569.433 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:02:51.888Z,1741712571.888 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:02:51.888Z,1741712571.888 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:02:51.888Z,1741712571.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:02:51.889Z,1741712571.889 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:02:52.285Z,1741712572.285 [Default:CheckIn:D] Stopped 2025-03-11T17:02:52.285Z,1741712572.285 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:02:52.692Z,1741712572.692 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.350179 min 2025-03-11T17:02:52.692Z,1741712572.692 [Default:CheckIn:E] Stopped 2025-03-11T17:02:52.692Z,1741712572.692 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:02:52.692Z,1741712572.692 [Default:CheckIn] Stopped 2025-03-11T17:02:52.693Z,1741712572.693 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:02:52.693Z,1741712572.693 [Default:CheckIn](INFO): Running loop #9 2025-03-11T17:02:52.693Z,1741712572.693 [Default:CheckIn] Running Loop=9 2025-03-11T17:02:52.693Z,1741712572.693 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:02:52.693Z,1741712572.693 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:02:54.688Z,1741712574.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170253.00,A,3648.16043,N,12147.28948,W,0.136,0.00,110325,,,A*79 2025-03-11T17:02:54.690Z,1741712574.690 [NAL9602](INFO): GPS fix at 20250311T170253: (36.802674, -121.788158) 2025-03-11T17:02:54.730Z,1741712574.730 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:02:54.730Z,1741712574.730 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:03:00.823Z,1741712580.823 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:03:02.611Z,1741712582.611 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0028.lzma 2025-03-11T17:03:03.613Z,1741712583.613 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0028.lzma.bak 2025-03-11T17:03:03.614Z,1741712583.614 [DataOverHttps](INFO): SBD MOMSN=24177368 2025-03-11T17:03:13.751Z,1741712593.751 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-03-11T17:03:19.804Z,1741712599.804 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250311T155306/Express0029.lzma 2025-03-11T17:03:20.806Z,1741712600.806 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0029.lzma.bak 2025-03-11T17:03:20.806Z,1741712600.806 [DataOverHttps](INFO): SBD MOMSN=24177371 2025-03-11T17:03:21.879Z,1741712601.879 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:03:21.880Z,1741712601.880 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:03:21.880Z,1741712601.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:05:34.404Z,1741712734.404 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-11T17:05:35.582Z,1741712735.582 [NAL9602](INFO): SBD MO Status=0, MOMSN=62128, MT Status=0, MTMSN=0 2025-03-11T17:05:35.583Z,1741712735.583 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:05:40.870Z,1741712740.870 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:05:55.364Z,1741712755.364 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:06:06.267Z,1741712766.267 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:06:11.107Z,1741712771.107 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:06:26.459Z,1741712786.459 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:06:41.409Z,1741712801.409 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:06:56.760Z,1741712816.760 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:07:12.516Z,1741712832.516 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:07:28.279Z,1741712848.279 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:07:44.027Z,1741712864.027 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:07:58.979Z,1741712878.979 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T17:08:05.042Z,1741712885.042 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5. 2025-03-11T17:08:05.045Z,1741712885.045 [BPC1](INFO): Received data from all battery sticks. 2025-03-11T17:08:22.437Z,1741712902.437 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:08:22.437Z,1741712902.437 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:08:22.437Z,1741712902.437 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:08:22.437Z,1741712902.437 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:08:22.839Z,1741712902.839 [Default:CheckIn:D] Stopped 2025-03-11T17:08:22.839Z,1741712902.839 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.859408 min 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn:E] Stopped 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn] Stopped 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn](INFO): Running loop #10 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn] Running Loop=10 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:08:23.236Z,1741712903.236 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:08:25.246Z,1741712905.246 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170824.00,A,3648.16370,N,12147.28668,W,0.019,0.00,110325,,,A*71 2025-03-11T17:08:25.249Z,1741712905.249 [NAL9602](INFO): GPS fix at 20250311T170824: (36.802728, -121.788111) 2025-03-11T17:08:25.259Z,1741712905.259 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:08:25.259Z,1741712905.259 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:08:32.503Z,1741712912.503 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20250311T155306/Courier0031.lzma 2025-03-11T17:08:33.505Z,1741712913.505 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0031.lzma.bak 2025-03-11T17:08:33.506Z,1741712913.506 [DataOverHttps](INFO): SBD MOMSN=24177661 2025-03-11T17:08:51.164Z,1741712931.164 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250311T155306/Express0032.lzma 2025-03-11T17:08:52.166Z,1741712932.166 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0032.lzma.bak 2025-03-11T17:08:52.166Z,1741712932.166 [DataOverHttps](INFO): SBD MOMSN=24177664 2025-03-11T17:08:53.561Z,1741712933.561 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:08:53.561Z,1741712933.561 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:08:53.561Z,1741712933.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:13:13.746Z,1741713193.746 [NAL9602](INFO): SBD MO Status=0, MOMSN=62129, MT Status=0, MTMSN=0 2025-03-11T17:13:13.746Z,1741713193.746 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:13:44.453Z,1741713224.453 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:13:54.155Z,1741713234.155 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:13:54.155Z,1741713234.155 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:13:54.155Z,1741713234.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:13:54.155Z,1741713234.155 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:13:54.562Z,1741713234.562 [Default:CheckIn:D] Stopped 2025-03-11T17:13:54.562Z,1741713234.562 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:13:54.971Z,1741713234.971 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.388127 min 2025-03-11T17:13:54.971Z,1741713234.971 [Default:CheckIn:E] Stopped 2025-03-11T17:13:54.972Z,1741713234.972 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:13:54.972Z,1741713234.972 [Default:CheckIn] Stopped 2025-03-11T17:13:54.972Z,1741713234.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:13:54.972Z,1741713234.972 [Default:CheckIn](INFO): Running loop #11 2025-03-11T17:13:54.972Z,1741713234.972 [Default:CheckIn] Running Loop=11 2025-03-11T17:13:54.972Z,1741713234.972 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:13:54.972Z,1741713234.972 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:13:56.976Z,1741713236.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171356.00,A,3648.16223,N,12147.28926,W,0.428,0.00,110325,,,A*7A 2025-03-11T17:13:56.978Z,1741713236.978 [NAL9602](INFO): GPS fix at 20250311T171356: (36.802704, -121.788154) 2025-03-11T17:13:57.006Z,1741713237.006 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:13:57.006Z,1741713237.006 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:14:04.483Z,1741713244.483 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250311T155306/Courier0034.lzma 2025-03-11T17:14:05.486Z,1741713245.486 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0034.lzma.bak 2025-03-11T17:14:05.486Z,1741713245.486 [DataOverHttps](INFO): SBD MOMSN=24177675 2025-03-11T17:14:19.215Z,1741713259.215 [NAL9602](INFO): SBD MO Status=2, MOMSN=62130, MT Status=2, MTMSN=0 2025-03-11T17:14:19.215Z,1741713259.215 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T17:14:24.228Z,1741713264.228 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20250311T155306/Express0035.lzma 2025-03-11T17:14:25.230Z,1741713265.230 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0035.lzma.bak 2025-03-11T17:14:25.230Z,1741713265.230 [DataOverHttps](INFO): SBD MOMSN=24177679 2025-03-11T17:14:26.549Z,1741713266.549 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:14:26.549Z,1741713266.549 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:14:26.549Z,1741713266.549 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:14:37.014Z,1741713277.014 [NAL9602](INFO): SBD MO Status=0, MOMSN=62130, MT Status=0, MTMSN=0 2025-03-11T17:14:37.014Z,1741713277.014 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:15:07.730Z,1741713307.730 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:19:27.123Z,1741713567.123 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:19:27.123Z,1741713567.123 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:19:27.123Z,1741713567.123 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:19:27.123Z,1741713567.123 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:19:27.535Z,1741713567.535 [Default:CheckIn:D] Stopped 2025-03-11T17:19:27.536Z,1741713567.536 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:19:27.939Z,1741713567.939 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.937679 min 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn:E] Stopped 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn] Stopped 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn](INFO): Running loop #12 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn] Running Loop=12 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:19:27.940Z,1741713567.940 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:19:29.946Z,1741713569.946 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171929.00,A,3648.16696,N,12147.29345,W,0.311,0.00,110325,,,A*71 2025-03-11T17:19:29.949Z,1741713569.949 [NAL9602](INFO): GPS fix at 20250311T171929: (36.802783, -121.788224) 2025-03-11T17:19:29.980Z,1741713569.980 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:19:29.980Z,1741713569.980 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:19:37.139Z,1741713577.139 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0037.lzma 2025-03-11T17:19:38.141Z,1741713578.141 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0037.lzma.bak 2025-03-11T17:19:38.142Z,1741713578.142 [DataOverHttps](INFO): SBD MOMSN=24177709 2025-03-11T17:19:54.276Z,1741713594.276 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250311T155306/Express0038.lzma 2025-03-11T17:19:55.282Z,1741713595.282 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0038.lzma.bak 2025-03-11T17:19:55.282Z,1741713595.282 [DataOverHttps](INFO): SBD MOMSN=24177712 2025-03-11T17:19:56.629Z,1741713596.629 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:19:56.629Z,1741713596.629 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:19:56.629Z,1741713596.629 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:21:05.694Z,1741713665.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=62131, MT Status=2, MTMSN=0 2025-03-11T17:21:05.694Z,1741713665.694 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T17:23:25.475Z,1741713805.475 [NAL9602](INFO): SBD MO Status=0, MOMSN=62131, MT Status=0, MTMSN=0 2025-03-11T17:23:25.475Z,1741713805.475 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:23:56.177Z,1741713836.177 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:24:57.211Z,1741713897.211 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:24:57.216Z,1741713897.216 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:24:57.216Z,1741713897.216 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:24:57.216Z,1741713897.216 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:24:57.616Z,1741713897.616 [Default:CheckIn:D] Stopped 2025-03-11T17:24:57.616Z,1741713897.616 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:24:58.000Z,1741713898.000 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.439030 min 2025-03-11T17:24:58.000Z,1741713898.000 [Default:CheckIn:E] Stopped 2025-03-11T17:24:58.000Z,1741713898.000 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:24:58.000Z,1741713898.000 [Default:CheckIn] Stopped 2025-03-11T17:24:58.001Z,1741713898.001 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:24:58.001Z,1741713898.001 [Default:CheckIn](INFO): Running loop #13 2025-03-11T17:24:58.001Z,1741713898.001 [Default:CheckIn] Running Loop=13 2025-03-11T17:24:58.001Z,1741713898.001 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:24:58.001Z,1741713898.001 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:25:00.014Z,1741713900.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172459.00,A,3648.16790,N,12147.28613,W,1.186,35.41,110325,,,A*46 2025-03-11T17:25:00.017Z,1741713900.017 [NAL9602](INFO): GPS fix at 20250311T172459: (36.802798, -121.788102) 2025-03-11T17:25:00.027Z,1741713900.027 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:25:00.028Z,1741713900.028 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:25:07.583Z,1741713907.583 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0040.lzma 2025-03-11T17:25:08.586Z,1741713908.586 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0040.lzma.bak 2025-03-11T17:25:08.586Z,1741713908.586 [DataOverHttps](INFO): SBD MOMSN=24178082 2025-03-11T17:25:24.744Z,1741713924.744 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250311T155306/Express0041.lzma 2025-03-11T17:25:25.746Z,1741713925.746 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0041.lzma.bak 2025-03-11T17:25:25.746Z,1741713925.746 [DataOverHttps](INFO): SBD MOMSN=24178085 2025-03-11T17:25:27.095Z,1741713927.095 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:25:27.095Z,1741713927.095 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:25:27.095Z,1741713927.095 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:26:00.206Z,1741713960.206 [NAL9602](INFO): SBD MO Status=2, MOMSN=62132, MT Status=2, MTMSN=0 2025-03-11T17:26:00.206Z,1741713960.206 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T17:27:00.824Z,1741714020.824 [NAL9602](INFO): SBD MO Status=0, MOMSN=62132, MT Status=0, MTMSN=0 2025-03-11T17:27:00.824Z,1741714020.824 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:27:31.517Z,1741714051.517 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:30:27.683Z,1741714227.683 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:30:27.683Z,1741714227.683 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:30:27.683Z,1741714227.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:30:27.683Z,1741714227.683 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:30:28.091Z,1741714228.091 [Default:CheckIn:D] Stopped 2025-03-11T17:30:28.091Z,1741714228.091 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:30:28.501Z,1741714228.501 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.946948 min 2025-03-11T17:30:28.501Z,1741714228.501 [Default:CheckIn:E] Stopped 2025-03-11T17:30:28.501Z,1741714228.501 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:30:28.501Z,1741714228.501 [Default:CheckIn] Stopped 2025-03-11T17:30:28.501Z,1741714228.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:30:28.502Z,1741714228.502 [Default:CheckIn](INFO): Running loop #14 2025-03-11T17:30:28.502Z,1741714228.502 [Default:CheckIn] Running Loop=14 2025-03-11T17:30:28.502Z,1741714228.502 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:30:28.502Z,1741714228.502 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:30:30.499Z,1741714230.499 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173029.00,A,3648.16336,N,12147.28790,W,0.194,55.86,110325,,,A*49 2025-03-11T17:30:30.501Z,1741714230.501 [NAL9602](INFO): GPS fix at 20250311T173029: (36.802723, -121.788132) 2025-03-11T17:30:30.517Z,1741714230.517 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:30:30.517Z,1741714230.517 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:30:38.039Z,1741714238.039 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0043.lzma 2025-03-11T17:30:38.926Z,1741714238.926 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0043.lzma.bak 2025-03-11T17:30:38.926Z,1741714238.926 [DataOverHttps](INFO): SBD MOMSN=24178116 2025-03-11T17:30:57.680Z,1741714257.680 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250311T155306/Express0044.lzma 2025-03-11T17:30:58.682Z,1741714258.682 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0044.lzma.bak 2025-03-11T17:30:58.682Z,1741714258.682 [DataOverHttps](INFO): SBD MOMSN=24178119 2025-03-11T17:31:00.056Z,1741714260.056 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:31:00.056Z,1741714260.056 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:31:00.056Z,1741714260.056 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:34:55.596Z,1741714495.596 [NAL9602](INFO): SBD MO Status=2, MOMSN=62133, MT Status=2, MTMSN=0 2025-03-11T17:34:55.596Z,1741714495.596 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T17:35:32.353Z,1741714532.353 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-03-11T17:36:00.639Z,1741714560.639 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:36:00.639Z,1741714560.639 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:36:00.640Z,1741714560.640 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:36:00.640Z,1741714560.640 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:36:01.047Z,1741714561.047 [Default:CheckIn:D] Stopped 2025-03-11T17:36:01.047Z,1741714561.047 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:36:01.462Z,1741714561.462 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.496216 min 2025-03-11T17:36:01.462Z,1741714561.462 [Default:CheckIn:E] Stopped 2025-03-11T17:36:01.462Z,1741714561.462 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:36:01.462Z,1741714561.462 [Default:CheckIn] Stopped 2025-03-11T17:36:01.463Z,1741714561.463 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:36:01.463Z,1741714561.463 [Default:CheckIn](INFO): Running loop #15 2025-03-11T17:36:01.463Z,1741714561.463 [Default:CheckIn] Running Loop=15 2025-03-11T17:36:01.463Z,1741714561.463 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:36:01.463Z,1741714561.463 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:36:03.455Z,1741714563.455 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173602.00,A,3648.16923,N,12147.28244,W,0.292,55.86,110325,,,A*41 2025-03-11T17:36:03.458Z,1741714563.458 [NAL9602](INFO): GPS fix at 20250311T173602: (36.802821, -121.788041) 2025-03-11T17:36:03.493Z,1741714563.493 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:36:03.493Z,1741714563.493 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:36:11.239Z,1741714571.239 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0046.lzma 2025-03-11T17:36:12.242Z,1741714572.242 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0046.lzma.bak 2025-03-11T17:36:12.242Z,1741714572.242 [DataOverHttps](INFO): SBD MOMSN=24178128 2025-03-11T17:36:31.784Z,1741714591.784 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20250311T155306/Express0047.lzma 2025-03-11T17:36:32.786Z,1741714592.786 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0047.lzma.bak 2025-03-11T17:36:32.786Z,1741714592.786 [DataOverHttps](INFO): SBD MOMSN=24178131 2025-03-11T17:36:33.822Z,1741714593.822 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:36:33.822Z,1741714593.822 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:36:33.822Z,1741714593.822 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:36:35.410Z,1741714595.410 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:41:34.383Z,1741714894.383 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:41:34.383Z,1741714894.383 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:41:34.383Z,1741714894.383 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:41:34.383Z,1741714894.383 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:41:34.797Z,1741714894.797 [Default:CheckIn:D] Stopped 2025-03-11T17:41:34.797Z,1741714894.797 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.058708 min 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn:E] Stopped 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn] Stopped 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn](INFO): Running loop #16 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn] Running Loop=16 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:41:35.213Z,1741714895.213 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:41:37.207Z,1741714897.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174136.00,A,3648.14593,N,12147.25226,W,0.914,171.01,110325,,,A*77 2025-03-11T17:41:37.209Z,1741714897.209 [NAL9602](INFO): GPS fix at 20250311T174136: (36.802432, -121.787538) 2025-03-11T17:41:37.220Z,1741714897.220 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:41:37.220Z,1741714897.220 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:41:45.279Z,1741714905.279 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250311T155306/Courier0049.lzma 2025-03-11T17:41:46.282Z,1741714906.282 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0049.lzma.bak 2025-03-11T17:41:46.282Z,1741714906.282 [DataOverHttps](INFO): SBD MOMSN=24178147 2025-03-11T17:42:02.296Z,1741714922.296 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20250311T155306/Express0050.lzma 2025-03-11T17:42:03.298Z,1741714923.298 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0050.lzma.bak 2025-03-11T17:42:03.298Z,1741714923.298 [DataOverHttps](INFO): SBD MOMSN=24178150 2025-03-11T17:42:04.684Z,1741714924.684 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:42:04.684Z,1741714924.684 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:42:04.684Z,1741714924.684 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:42:07.921Z,1741714927.921 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-03-11T17:42:07.996Z,1741714927.996 [NAL9602](ERROR): received: +CSQ:0 OK133, 2, 0, 0, 0 OK 2025-03-11T17:42:36.186Z,1741714956.186 [NAL9602](INFO): SBD MO Status=0, MOMSN=62133, MT Status=0, MTMSN=0 2025-03-11T17:42:36.186Z,1741714956.186 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:43:06.889Z,1741714986.889 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:46:16.313Z,1741715176.313 [DataOverHttps](IMPORTANT): SBD MTMSN=20250311T174615 2025-03-11T17:46:26.600Z,1741715186.600 [DataOverHttps](INFO): Received command: ibit 2025-03-11T17:46:26.645Z,1741715186.645 [CommandExec](IMPORTANT): got command ibit 2025-03-11T17:46:26.987Z,1741715186.987 [IBIT](IMPORTANT): Beginning Initiated BIT 2025-03-11T17:46:26.987Z,1741715186.987 [IBIT](IMPORTANT): Beginning control surface checks. 2025-03-11T17:46:26.994Z,1741715186.994 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-03-11T17:46:28.564Z,1741715188.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174627.00,A,3648.13492,N,12147.21321,W,0.058,84.05,110325,,,D*4E 2025-03-11T17:46:28.566Z,1741715188.566 [NAL9602](INFO): GPS fix at 20250311T174627: (36.802249, -121.786887) 2025-03-11T17:46:31.583Z,1741715191.583 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.002502 CHAN A1 (24V): 0.000197 CHAN A2 (12V): -0.002165 CHAN A3 (5V): -0.000988 CHAN B0 (3.3V): 0.000110 CHAN B1 (3.15aV): 0.000575 CHAN B2 (3.15bV): 4.767929 CHAN B3 (GND): -0.000274 OPEN: -0.000597 Full Scale: +/- 1 mA 2025-03-11T17:46:51.637Z,1741715211.637 [NAL9602](INFO): SBD MO Status=0, MOMSN=62134, MT Status=0, MTMSN=0 2025-03-11T17:46:51.637Z,1741715211.637 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:46:52.848Z,1741715212.848 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174652.00,A,3648.13484,N,12147.21335,W,0.058,84.05,110325,,,D*4E 2025-03-11T17:46:52.850Z,1741715212.850 [NAL9602](INFO): GPS fix at 20250311T174652: (36.802247, -121.786889) 2025-03-11T17:46:56.124Z,1741715216.124 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174655.00,A,3648.13489,N,12147.21337,W,0.019,84.05,110325,,,D*43 2025-03-11T17:46:56.126Z,1741715216.126 [NAL9602](INFO): GPS fix at 20250311T174655: (36.802248, -121.786890) 2025-03-11T17:46:58.923Z,1741715218.923 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174658.00,A,3648.13492,N,12147.21337,W,0.019,84.05,110325,,,D*44 2025-03-11T17:46:58.925Z,1741715218.925 [NAL9602](INFO): GPS fix at 20250311T174658: (36.802249, -121.786890) 2025-03-11T17:47:02.150Z,1741715222.150 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174701.00,A,3648.13495,N,12147.21341,W,0.019,84.05,110325,,,D*4F 2025-03-11T17:47:02.153Z,1741715222.153 [NAL9602](INFO): GPS fix at 20250311T174701: (36.802249, -121.786890) 2025-03-11T17:47:04.979Z,1741715224.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174704.00,A,3648.13499,N,12147.21342,W,0.039,84.05,110325,,,D*47 2025-03-11T17:47:04.981Z,1741715224.981 [NAL9602](INFO): GPS fix at 20250311T174704: (36.802250, -121.786890) 2025-03-11T17:47:08.215Z,1741715228.215 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174707.00,A,3648.13501,N,12147.21339,W,0.019,84.05,110325,,,D*4A 2025-03-11T17:47:08.226Z,1741715228.226 [NAL9602](INFO): GPS fix at 20250311T174707: (36.802250, -121.786890) 2025-03-11T17:47:11.043Z,1741715231.043 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174710.00,A,3648.13497,N,12147.21333,W,0.019,84.05,110325,,,D*48 2025-03-11T17:47:11.045Z,1741715231.045 [NAL9602](INFO): GPS fix at 20250311T174710: (36.802250, -121.786889) 2025-03-11T17:47:13.082Z,1741715233.082 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 2 Latitude: 36.802250 Longitude: -121.786888 2025-03-11T17:47:13.528Z,1741715233.528 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 15.620000 2025-03-11T17:47:13.528Z,1741715233.528 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2025-03-11T17:47:13.529Z,1741715233.529 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2025-03-11T17:47:13.871Z,1741715233.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174713.00,A,3648.13487,N,12147.21326,W,0.019,84.05,110325,,,D*4E 2025-03-11T17:47:13.882Z,1741715233.882 [NAL9602](INFO): GPS fix at 20250311T174713: (36.802248, -121.786888) 2025-03-11T17:47:13.899Z,1741715233.899 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2025-03-11T17:47:13.899Z,1741715233.899 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2025-03-11T17:47:13.899Z,1741715233.899 [IBIT](IMPORTANT): Pressure:9.388451 PSI 2025-03-11T17:47:13.901Z,1741715233.901 [IBIT](IMPORTANT): Humidity:16.841656 % 2025-03-11T17:47:14.318Z,1741715234.318 [IBIT](IMPORTANT): Vehicle Pitch:-0.080215 degrees 2025-03-11T17:47:14.318Z,1741715234.318 [IBIT](IMPORTANT): Vehicle Roll:6.453598 degrees 2025-03-11T17:47:14.318Z,1741715234.318 [IBIT](IMPORTANT): Vehicle Heading:220.747116 degrees 2025-03-11T17:47:14.693Z,1741715234.693 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2025-03-11T17:47:14.694Z,1741715234.694 [IBIT](IMPORTANT): buoyancyNeutral: 162.399979 cc 2025-03-11T17:47:14.694Z,1741715234.694 [IBIT](IMPORTANT): massDefault: 1.432986 cm 2025-03-11T17:47:14.694Z,1741715234.694 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2025-03-11T17:47:14.695Z,1741715234.695 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2025-03-11T17:47:14.695Z,1741715234.695 [IBIT](IMPORTANT): IBIT PASSED 2025-03-11T17:47:15.096Z,1741715235.096 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:47:15.096Z,1741715235.096 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:47:15.096Z,1741715235.096 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:47:15.097Z,1741715235.097 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:47:15.510Z,1741715235.510 [Default:CheckIn:D] Stopped 2025-03-11T17:47:15.510Z,1741715235.510 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.737248 min 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn:E] Stopped 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn] Stopped 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn](INFO): Running loop #17 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn] Running Loop=17 2025-03-11T17:47:15.928Z,1741715235.928 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:47:15.929Z,1741715235.929 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:47:18.311Z,1741715238.311 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174717.00,A,3648.13480,N,12147.21324,W,0.039,84.05,110325,,,D*4D 2025-03-11T17:47:18.324Z,1741715238.324 [NAL9602](INFO): GPS fix at 20250311T174717: (36.802247, -121.786887) 2025-03-11T17:47:18.335Z,1741715238.335 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:47:18.335Z,1741715238.335 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:47:25.103Z,1741715245.103 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0052.lzma 2025-03-11T17:47:26.107Z,1741715246.107 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0052.lzma.bak 2025-03-11T17:47:26.107Z,1741715246.107 [DataOverHttps](INFO): SBD MOMSN=24178180 2025-03-11T17:47:42.435Z,1741715262.435 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250311T155306/Courier0055.lzma 2025-03-11T17:47:43.438Z,1741715263.438 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0055.lzma.bak 2025-03-11T17:47:43.438Z,1741715263.438 [DataOverHttps](INFO): SBD MOMSN=24178205 2025-03-11T17:47:50.628Z,1741715270.628 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:47:59.838Z,1741715279.838 [DataOverHttps](INFO): Sending 984 bytes from file Logs/20250311T155306/Express0053.lzma 2025-03-11T17:48:00.838Z,1741715280.838 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0053.lzma.bak 2025-03-11T17:48:00.838Z,1741715280.838 [DataOverHttps](INFO): SBD MOMSN=24178230 2025-03-11T17:48:17.219Z,1741715297.219 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20250311T155306/Express0056.lzma 2025-03-11T17:48:18.225Z,1741715298.225 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0056.lzma.bak 2025-03-11T17:48:18.225Z,1741715298.225 [DataOverHttps](INFO): SBD MOMSN=24178266 2025-03-11T17:48:19.352Z,1741715299.352 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:48:19.352Z,1741715299.352 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:48:19.352Z,1741715299.352 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:53:20.051Z,1741715600.051 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:53:20.051Z,1741715600.051 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:53:20.051Z,1741715600.051 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:53:20.051Z,1741715600.051 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:53:20.451Z,1741715600.451 [Default:CheckIn:D] Stopped 2025-03-11T17:53:20.451Z,1741715600.451 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:53:20.864Z,1741715600.864 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.819613 min 2025-03-11T17:53:20.864Z,1741715600.864 [Default:CheckIn:E] Stopped 2025-03-11T17:53:20.864Z,1741715600.864 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:53:20.864Z,1741715600.864 [Default:CheckIn] Stopped 2025-03-11T17:53:20.864Z,1741715600.864 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:53:20.864Z,1741715600.864 [Default:CheckIn](INFO): Running loop #18 2025-03-11T17:53:20.865Z,1741715600.865 [Default:CheckIn] Running Loop=18 2025-03-11T17:53:20.865Z,1741715600.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:53:20.865Z,1741715600.865 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:53:22.867Z,1741715602.867 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175322.00,A,3648.13403,N,12147.21318,W,0.019,84.05,110325,,,D*48 2025-03-11T17:53:22.878Z,1741715602.878 [NAL9602](INFO): GPS fix at 20250311T175322: (36.802234, -121.786886) 2025-03-11T17:53:22.889Z,1741715602.889 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:53:22.890Z,1741715602.890 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:53:30.623Z,1741715610.623 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0058.lzma 2025-03-11T17:53:31.626Z,1741715611.626 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0058.lzma.bak 2025-03-11T17:53:31.626Z,1741715611.626 [DataOverHttps](INFO): SBD MOMSN=24178331 2025-03-11T17:53:34.678Z,1741715614.678 [NAL9602](INFO): SBD MO Status=0, MOMSN=62135, MT Status=0, MTMSN=0 2025-03-11T17:53:34.678Z,1741715614.678 [NAL9602](INFO): No messages in MT queue 2025-03-11T17:53:48.140Z,1741715628.140 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250311T155306/Express0059.lzma 2025-03-11T17:53:49.142Z,1741715629.142 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0059.lzma.bak 2025-03-11T17:53:49.142Z,1741715629.142 [DataOverHttps](INFO): SBD MOMSN=24178335 2025-03-11T17:53:50.411Z,1741715630.411 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:53:50.411Z,1741715630.411 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:53:50.411Z,1741715630.411 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:54:05.340Z,1741715645.340 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T17:58:51.093Z,1741715931.093 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T17:58:51.093Z,1741715931.093 [Default:CheckIn:C.Wait] Stopped 2025-03-11T17:58:51.093Z,1741715931.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T17:58:51.093Z,1741715931.093 [Default:CheckIn:D] Running Loop=1 2025-03-11T17:58:51.500Z,1741715931.500 [Default:CheckIn:D] Stopped 2025-03-11T17:58:51.500Z,1741715931.500 [Default:CheckIn:E] Running Loop=1 2025-03-11T17:58:51.928Z,1741715931.928 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.337085 min 2025-03-11T17:58:51.928Z,1741715931.928 [Default:CheckIn:E] Stopped 2025-03-11T17:58:51.928Z,1741715931.928 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T17:58:51.928Z,1741715931.928 [Default:CheckIn] Stopped 2025-03-11T17:58:51.928Z,1741715931.928 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T17:58:51.929Z,1741715931.929 [Default:CheckIn](INFO): Running loop #19 2025-03-11T17:58:51.929Z,1741715931.929 [Default:CheckIn] Running Loop=19 2025-03-11T17:58:51.929Z,1741715931.929 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T17:58:51.929Z,1741715931.929 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T17:58:53.904Z,1741715933.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175853.00,A,3648.13384,N,12147.21307,W,0.000,84.05,110325,,,D*4B 2025-03-11T17:58:53.906Z,1741715933.906 [NAL9602](INFO): GPS fix at 20250311T175853: (36.802231, -121.786884) 2025-03-11T17:58:53.949Z,1741715933.949 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T17:58:53.949Z,1741715933.949 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T17:59:01.729Z,1741715941.729 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250311T155306/Courier0061.lzma 2025-03-11T17:59:02.731Z,1741715942.731 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0061.lzma.bak 2025-03-11T17:59:02.731Z,1741715942.731 [DataOverHttps](INFO): SBD MOMSN=24178352 2025-03-11T17:59:12.556Z,1741715952.556 [NAL9602](INFO): SBD MO Status=2, MOMSN=62136, MT Status=2, MTMSN=0 2025-03-11T17:59:12.556Z,1741715952.556 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-11T17:59:19.006Z,1741715959.006 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250311T155306/Express0062.lzma 2025-03-11T17:59:20.002Z,1741715960.002 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0062.lzma.bak 2025-03-11T17:59:20.002Z,1741715960.002 [DataOverHttps](INFO): SBD MOMSN=24178358 2025-03-11T17:59:21.057Z,1741715961.057 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T17:59:21.057Z,1741715961.057 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T17:59:21.057Z,1741715961.057 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T17:59:30.338Z,1741715970.338 [NAL9602](INFO): SBD MO Status=0, MOMSN=62136, MT Status=0, MTMSN=0 2025-03-11T17:59:30.338Z,1741715970.338 [NAL9602](INFO): No messages in MT queue 2025-03-11T18:00:01.043Z,1741716001.043 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T18:04:21.778Z,1741716261.778 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T18:04:21.778Z,1741716261.778 [Default:CheckIn:C.Wait] Stopped 2025-03-11T18:04:21.779Z,1741716261.779 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T18:04:21.779Z,1741716261.779 [Default:CheckIn:D] Running Loop=1 2025-03-11T18:04:22.204Z,1741716262.204 [Default:CheckIn:D] Stopped 2025-03-11T18:04:22.204Z,1741716262.204 [Default:CheckIn:E] Running Loop=1 2025-03-11T18:04:22.614Z,1741716262.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.848617 min 2025-03-11T18:04:22.614Z,1741716262.614 [Default:CheckIn:E] Stopped 2025-03-11T18:04:22.614Z,1741716262.614 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T18:04:22.614Z,1741716262.614 [Default:CheckIn] Stopped 2025-03-11T18:04:22.614Z,1741716262.614 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T18:04:22.614Z,1741716262.614 [Default:CheckIn](INFO): Running loop #20 2025-03-11T18:04:22.614Z,1741716262.614 [Default:CheckIn] Running Loop=20 2025-03-11T18:04:22.615Z,1741716262.615 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T18:04:22.615Z,1741716262.615 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T18:04:24.595Z,1741716264.595 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180423.00,A,3648.13432,N,12147.21408,W,0.019,84.05,110325,,,D*40 2025-03-11T18:04:24.597Z,1741716264.597 [NAL9602](INFO): GPS fix at 20250311T180423: (36.802239, -121.786901) 2025-03-11T18:04:24.664Z,1741716264.664 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T18:04:24.664Z,1741716264.664 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T18:04:32.699Z,1741716272.699 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0064.lzma 2025-03-11T18:04:33.705Z,1741716273.705 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0064.lzma.bak 2025-03-11T18:04:33.705Z,1741716273.705 [DataOverHttps](INFO): SBD MOMSN=24178381 2025-03-11T18:04:37.214Z,1741716277.214 [NAL9602](INFO): SBD MO Status=0, MOMSN=62137, MT Status=0, MTMSN=0 2025-03-11T18:04:37.214Z,1741716277.214 [NAL9602](INFO): No messages in MT queue 2025-03-11T18:04:51.776Z,1741716291.776 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250311T155306/Express0065.lzma 2025-03-11T18:04:52.772Z,1741716292.772 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0065.lzma.bak 2025-03-11T18:04:52.772Z,1741716292.772 [DataOverHttps](INFO): SBD MOMSN=24178387 2025-03-11T18:04:53.848Z,1741716293.848 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T18:04:53.848Z,1741716293.848 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T18:04:53.848Z,1741716293.848 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T18:05:07.957Z,1741716307.957 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T18:09:11.159Z,1741716551.159 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:09:23.279Z,1741716563.279 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:09:34.187Z,1741716574.187 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:09:45.903Z,1741716585.903 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:09:54.400Z,1741716594.400 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T18:09:54.400Z,1741716594.400 [Default:CheckIn:C.Wait] Stopped 2025-03-11T18:09:54.400Z,1741716594.400 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T18:09:54.400Z,1741716594.400 [Default:CheckIn:D] Running Loop=1 2025-03-11T18:09:54.805Z,1741716594.805 [Default:CheckIn:D] Stopped 2025-03-11T18:09:54.805Z,1741716594.805 [Default:CheckIn:E] Running Loop=1 2025-03-11T18:09:55.217Z,1741716595.217 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.392179 min 2025-03-11T18:09:55.217Z,1741716595.217 [Default:CheckIn:E] Stopped 2025-03-11T18:09:55.217Z,1741716595.217 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T18:09:55.218Z,1741716595.218 [Default:CheckIn] Stopped 2025-03-11T18:09:55.218Z,1741716595.218 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T18:09:55.218Z,1741716595.218 [Default:CheckIn](INFO): Running loop #21 2025-03-11T18:09:55.218Z,1741716595.218 [Default:CheckIn] Running Loop=21 2025-03-11T18:09:55.218Z,1741716595.218 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T18:09:55.218Z,1741716595.218 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T18:09:56.194Z,1741716596.194 [CommandExec](IMPORTANT): got command gfscan 2025-03-11T18:09:56.580Z,1741716596.580 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-03-11T18:09:57.228Z,1741716597.228 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180956.00,A,3648.13390,N,12147.21290,W,0.019,84.05,110325,,,D*47 2025-03-11T18:09:57.230Z,1741716597.230 [NAL9602](INFO): GPS fix at 20250311T180956: (36.802232, -121.786882) 2025-03-11T18:09:57.268Z,1741716597.268 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T18:09:57.268Z,1741716597.268 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T18:09:58.177Z,1741716598.177 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:10:01.205Z,1741716601.205 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002624 CHAN A1 (24V): 0.000406 CHAN A2 (12V): -0.002472 CHAN A3 (5V): -0.001999 CHAN B0 (3.3V): 0.000076 CHAN B1 (3.15aV): -0.000398 CHAN B2 (3.15bV): -0.000693 CHAN B3 (GND): 0.000347 OPEN: -0.000342 Full Scale: +/- 1 mA 2025-03-11T18:10:05.044Z,1741716605.044 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250311T155306/Courier0067.lzma 2025-03-11T18:10:06.047Z,1741716606.047 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0067.lzma.bak 2025-03-11T18:10:06.047Z,1741716606.047 [DataOverHttps](INFO): SBD MOMSN=24178405 2025-03-11T18:10:10.293Z,1741716610.293 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:10:18.796Z,1741716618.796 [NAL9602](INFO): SBD MO Status=0, MOMSN=62138, MT Status=0, MTMSN=0 2025-03-11T18:10:18.796Z,1741716618.796 [NAL9602](INFO): No messages in MT queue 2025-03-11T18:10:21.680Z,1741716621.680 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:10:26.084Z,1741716626.084 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20250311T155306/Express0068.lzma 2025-03-11T18:10:27.086Z,1741716627.086 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0068.lzma.bak 2025-03-11T18:10:27.086Z,1741716627.086 [DataOverHttps](INFO): SBD MOMSN=24178410 2025-03-11T18:10:28.202Z,1741716628.202 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T18:10:28.202Z,1741716628.202 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T18:10:28.203Z,1741716628.203 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T18:10:33.844Z,1741716633.844 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:10:49.590Z,1741716649.590 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T18:13:13.008Z,1741716793.008 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:13:26.341Z,1741716806.341 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:13:40.140Z,1741716820.140 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:13:54.228Z,1741716834.228 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:14:08.370Z,1741716848.370 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:14:21.772Z,1741716861.772 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:14:25.517Z,1741716865.517 [RudderServo](ERROR): getPosition uart error serial timeout 2025-03-11T18:14:25.517Z,1741716865.517 [RudderServo](FAULT): Rudder uart error - getPosition..serial timeout 2025-03-11T18:14:25.517Z,1741716865.517 [RudderServo] Communications Fault, FailCount= 1 2025-03-11T18:14:25.517Z,1741716865.517 [RudderServo](ERROR): Communications Fault 2025-03-11T18:14:25.521Z,1741716865.521 [CBIT](ERROR): Communications Fault in component: RudderServo 2025-03-11T18:14:25.846Z,1741716865.846 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-03-11T18:14:25.846Z,1741716865.846 [RudderServo](INFO): Powering down 2025-03-11T18:14:26.227Z,1741716866.227 [RudderServo](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Current Limiter Activated. 2025-03-11T18:14:26.227Z,1741716866.227 [RudderServo] Hardware Fault, FailCount= 1 2025-03-11T18:14:26.227Z,1741716866.227 [RudderServo](ERROR): Hardware Fault 2025-03-11T18:14:26.627Z,1741716866.627 [RudderServo](DEBUG): Initializing EZServoServo. 2025-03-11T18:14:26.745Z,1741716866.745 [RudderServo](DEBUG): Initializing RudderServo. 2025-03-11T18:14:26.753Z,1741716866.753 [CBIT](INFO): Clearing failed state for component RudderServo 2025-03-11T18:14:26.753Z,1741716866.753 [RudderServo] No Fault, FailCount= 1 2025-03-11T18:14:35.495Z,1741716875.495 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:14:49.635Z,1741716889.635 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:15:02.969Z,1741716902.969 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:15:16.300Z,1741716916.300 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-11T18:15:28.837Z,1741716928.837 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T18:15:28.837Z,1741716928.837 [Default:CheckIn:C.Wait] Stopped 2025-03-11T18:15:28.837Z,1741716928.837 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T18:15:28.837Z,1741716928.837 [Default:CheckIn:D] Running Loop=1 2025-03-11T18:15:29.290Z,1741716929.290 [Default:CheckIn:D] Stopped 2025-03-11T18:15:29.290Z,1741716929.290 [Default:CheckIn:E] Running Loop=1 2025-03-11T18:15:29.639Z,1741716929.639 [BPC1](ERROR): Battery stick #44 (s/n: 0243) reported OVER_TEMP_ALARM. Status code: 0x1717. 2025-03-11T18:15:29.639Z,1741716929.639 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2025-03-11T18:15:29.658Z,1741716929.658 [BPC1](INFO): Received data from all battery sticks. 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.966927 min 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn:E] Stopped 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn] Stopped 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn](INFO): Running loop #22 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn] Running Loop=22 2025-03-11T18:15:29.678Z,1741716929.678 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T18:15:29.679Z,1741716929.679 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T18:15:31.655Z,1741716931.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181530.00,A,3648.13454,N,12147.21267,W,0.058,84.05,110325,,,D*48 2025-03-11T18:15:31.657Z,1741716931.657 [NAL9602](INFO): GPS fix at 20250311T181530: (36.802242, -121.786878) 2025-03-11T18:15:31.669Z,1741716931.669 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T18:15:31.669Z,1741716931.669 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T18:15:39.431Z,1741716939.431 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20250311T155306/Courier0070.lzma 2025-03-11T18:15:40.434Z,1741716940.434 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0070.lzma.bak 2025-03-11T18:15:40.434Z,1741716940.434 [DataOverHttps](INFO): SBD MOMSN=24178512 2025-03-11T18:15:43.778Z,1741716943.778 [NAL9602](INFO): SBD MO Status=0, MOMSN=62139, MT Status=0, MTMSN=0 2025-03-11T18:15:43.778Z,1741716943.778 [NAL9602](INFO): No messages in MT queue 2025-03-11T18:15:56.713Z,1741716956.713 [DataOverHttps](INFO): Sending 443 bytes from file Logs/20250311T155306/Express0071.lzma 2025-03-11T18:15:57.714Z,1741716957.714 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0071.lzma.bak 2025-03-11T18:15:57.714Z,1741716957.714 [DataOverHttps](INFO): SBD MOMSN=24178515 2025-03-11T18:15:58.752Z,1741716958.752 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T18:15:58.752Z,1741716958.752 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T18:15:58.753Z,1741716958.753 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T18:16:14.500Z,1741716974.500 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T18:20:59.331Z,1741717259.331 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T18:20:59.331Z,1741717259.331 [Default:CheckIn:C.Wait] Stopped 2025-03-11T18:20:59.331Z,1741717259.331 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T18:20:59.331Z,1741717259.331 [Default:CheckIn:D] Running Loop=1 2025-03-11T18:20:59.746Z,1741717259.746 [Default:CheckIn:D] Stopped 2025-03-11T18:20:59.746Z,1741717259.746 [Default:CheckIn:E] Running Loop=1 2025-03-11T18:21:00.139Z,1741717260.139 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.474528 min 2025-03-11T18:21:00.139Z,1741717260.139 [Default:CheckIn:E] Stopped 2025-03-11T18:21:00.139Z,1741717260.139 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T18:21:00.139Z,1741717260.139 [Default:CheckIn] Stopped 2025-03-11T18:21:00.139Z,1741717260.139 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T18:21:00.140Z,1741717260.140 [Default:CheckIn](INFO): Running loop #23 2025-03-11T18:21:00.140Z,1741717260.140 [Default:CheckIn] Running Loop=23 2025-03-11T18:21:00.140Z,1741717260.140 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T18:21:00.140Z,1741717260.140 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T18:21:02.151Z,1741717262.151 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182101.00,A,3648.13364,N,12147.21438,W,0.019,84.05,110325,,,D*40 2025-03-11T18:21:02.153Z,1741717262.153 [NAL9602](INFO): GPS fix at 20250311T182101: (36.802227, -121.786906) 2025-03-11T18:21:02.165Z,1741717262.165 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T18:21:02.165Z,1741717262.165 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T18:21:09.935Z,1741717269.935 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250311T155306/Courier0073.lzma 2025-03-11T18:21:10.938Z,1741717270.938 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0073.lzma.bak 2025-03-11T18:21:10.938Z,1741717270.938 [DataOverHttps](INFO): SBD MOMSN=24178614 2025-03-11T18:21:17.508Z,1741717277.508 [NAL9602](INFO): SBD MO Status=0, MOMSN=62140, MT Status=0, MTMSN=0 2025-03-11T18:21:17.508Z,1741717277.508 [NAL9602](INFO): No messages in MT queue 2025-03-11T18:21:27.512Z,1741717287.512 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250311T155306/Express0074.lzma 2025-03-11T18:21:28.514Z,1741717288.514 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0074.lzma.bak 2025-03-11T18:21:28.514Z,1741717288.514 [DataOverHttps](INFO): SBD MOMSN=24178617 2025-03-11T18:21:29.635Z,1741717289.635 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T18:21:29.652Z,1741717289.652 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T18:21:29.652Z,1741717289.652 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T18:21:48.209Z,1741717308.209 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T18:26:30.229Z,1741717590.229 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-11T18:26:30.229Z,1741717590.229 [Default:CheckIn:C.Wait] Stopped 2025-03-11T18:26:30.229Z,1741717590.229 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T18:26:30.229Z,1741717590.229 [Default:CheckIn:D] Running Loop=1 2025-03-11T18:26:30.639Z,1741717590.639 [Default:CheckIn:D] Stopped 2025-03-11T18:26:30.640Z,1741717590.640 [Default:CheckIn:E] Running Loop=1 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 148.989421 min 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn:E] Stopped 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn] Stopped 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn](INFO): Running loop #24 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn] Running Loop=24 2025-03-11T18:26:31.036Z,1741717591.036 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-11T18:26:31.037Z,1741717591.037 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-11T18:26:33.047Z,1741717593.047 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182632.00,A,3648.13447,N,12147.21255,W,0.078,84.05,110325,,,D*4B 2025-03-11T18:26:33.050Z,1741717593.050 [NAL9602](INFO): GPS fix at 20250311T182632: (36.802241, -121.786876) 2025-03-11T18:26:33.060Z,1741717593.060 [Default:CheckIn:Read_GPS] Stopped 2025-03-11T18:26:33.061Z,1741717593.061 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-11T18:26:40.764Z,1741717600.764 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250311T155306/Courier0076.lzma 2025-03-11T18:26:41.766Z,1741717601.766 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Courier0076.lzma.bak 2025-03-11T18:26:41.766Z,1741717601.766 [DataOverHttps](INFO): SBD MOMSN=24178637 2025-03-11T18:26:52.481Z,1741717612.481 [NAL9602](INFO): SBD MO Status=0, MOMSN=62141, MT Status=0, MTMSN=0 2025-03-11T18:26:52.481Z,1741717612.481 [NAL9602](INFO): No messages in MT queue 2025-03-11T18:27:02.056Z,1741717622.056 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250311T155306/Express0077.lzma 2025-03-11T18:27:03.225Z,1741717623.225 [DataOverHttps](INFO): Moved sent file to Logs/20250311T155306/Express0077.lzma.bak 2025-03-11T18:27:03.225Z,1741717623.225 [DataOverHttps](INFO): SBD MOMSN=24178640 2025-03-11T18:27:04.209Z,1741717624.209 [Default:CheckIn:Read_Iridium] Stopped 2025-03-11T18:27:04.209Z,1741717624.209 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-11T18:27:04.209Z,1741717624.209 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-11T18:27:21.721Z,1741717641.721 [CommandExec](IMPORTANT): got command restart application 2025-03-11T18:27:22.724Z,1741717642.724 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2025-03-11T18:27:22.724Z,1741717642.724 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:22.724Z,1741717642.724 [CommandExec](INFO): Uninitializing the command executive. 2025-03-11T18:27:22.724Z,1741717642.724 [CommandExec](INFO): Uninitializing the command scheduler. 2025-03-11T18:27:22.724Z,1741717642.724 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:22.788Z,1741717642.788 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-03-11T18:27:22.788Z,1741717642.788 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-03-11T18:27:22.788Z,1741717642.788 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:22.789Z,1741717642.789 [NavChartDb](INFO): Join timeout helper Thread ID is 1860 2025-03-11T18:27:23.072Z,1741717643.072 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:23.072Z,1741717643.072 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:23.088Z,1741717643.088 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-03-11T18:27:23.088Z,1741717643.088 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:23.088Z,1741717643.088 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1861 2025-03-11T18:27:23.189Z,1741717643.189 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-11T18:27:23.192Z,1741717643.192 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:23.192Z,1741717643.192 [WetLabsBB2FL](INFO): Powering down 2025-03-11T18:27:23.193Z,1741717643.193 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:23.200Z,1741717643.200 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-03-11T18:27:23.200Z,1741717643.200 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:23.200Z,1741717643.200 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1862 2025-03-11T18:27:24.056Z,1741717644.056 [CTD_Seabird](INFO): Powering down 2025-03-11T18:27:24.068Z,1741717644.068 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:24.068Z,1741717644.068 [CTD_Seabird](INFO): Powering down 2025-03-11T18:27:24.080Z,1741717644.080 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:24.082Z,1741717644.082 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-03-11T18:27:24.082Z,1741717644.082 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:24.082Z,1741717644.082 [Radio_Surface](INFO): Join timeout helper Thread ID is 1863 2025-03-11T18:27:24.200Z,1741717644.200 [Radio_Surface](INFO): Powering down 2025-03-11T18:27:24.201Z,1741717644.201 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:24.201Z,1741717644.201 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:24.208Z,1741717644.208 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-03-11T18:27:24.208Z,1741717644.208 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:24.208Z,1741717644.208 [Onboard](INFO): Join timeout helper Thread ID is 1864 2025-03-11T18:27:24.884Z,1741717644.884 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-03-11T18:27:26.212Z,1741717646.212 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:26.212Z,1741717646.212 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:26.232Z,1741717646.232 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-03-11T18:27:26.233Z,1741717646.233 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:26.233Z,1741717646.233 [DataOverHttps](INFO): Join timeout helper Thread ID is 1865 2025-03-11T18:27:26.892Z,1741717646.892 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:26.892Z,1741717646.892 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:26.896Z,1741717646.896 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-03-11T18:27:26.897Z,1741717646.897 [DAT ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:26.897Z,1741717646.897 [DAT](INFO): Join timeout helper Thread ID is 1866 2025-03-11T18:27:27.100Z,1741717647.100 [DAT](INFO): Powering down 2025-03-11T18:27:27.172Z,1741717647.172 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:27.172Z,1741717647.172 [DAT](INFO): Powering down 2025-03-11T18:27:27.173Z,1741717647.173 [DAT ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.184Z,1741717647.184 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-03-11T18:27:27.185Z,1741717647.185 [logger ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.185Z,1741717647.185 [logger](INFO): Join timeout helper Thread ID is 1867 2025-03-11T18:27:27.228Z,1741717647.228 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:27.229Z,1741717647.229 [logger ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.236Z,1741717647.236 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-03-11T18:27:27.237Z,1741717647.237 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.237Z,1741717647.237 [CommandLine](INFO): Join timeout helper Thread ID is 1868 2025-03-11T18:27:27.316Z,1741717647.316 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:27.316Z,1741717647.316 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.324Z,1741717647.324 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-03-11T18:27:27.324Z,1741717647.324 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.325Z,1741717647.325 [CommandExec](INFO): Join timeout helper Thread ID is 1869 2025-03-11T18:27:27.326Z,1741717647.326 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-03-11T18:27:27.326Z,1741717647.326 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.326Z,1741717647.326 [controlThread](INFO): Join timeout helper Thread ID is 1870 2025-03-11T18:27:27.381Z,1741717647.381 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-11T18:27:27.381Z,1741717647.381 [controlThread](DEBUG): Uninitializing ControlThread 2025-03-11T18:27:27.381Z,1741717647.381 [AHRS_M2](INFO): Powering down 2025-03-11T18:27:27.452Z,1741717647.452 [NAL9602](INFO): Powering down 2025-03-11T18:27:27.454Z,1741717647.454 [Sonardyne_Nano](INFO): Powering down 2025-03-11T18:27:27.573Z,1741717647.573 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-03-11T18:27:27.574Z,1741717647.574 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-03-11T18:27:27.574Z,1741717647.574 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-03-11T18:27:27.575Z,1741717647.575 [MissionManager](INFO): Uninitializing Mission Default 2025-03-11T18:27:27.575Z,1741717647.575 [Default] Stopped 2025-03-11T18:27:27.575Z,1741717647.575 [Default](DEBUG): Aggregate::uninitialize Default 2025-03-11T18:27:27.575Z,1741717647.575 [Default:B.GoToSurface] Stopped 2025-03-11T18:27:27.575Z,1741717647.575 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-03-11T18:27:27.575Z,1741717647.575 [Default:CheckIn] Stopped 2025-03-11T18:27:27.576Z,1741717647.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-11T18:27:27.576Z,1741717647.576 [Default:CheckIn:C.Wait] Stopped 2025-03-11T18:27:27.576Z,1741717647.576 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-11T18:27:27.579Z,1741717647.579 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-03-11T18:27:27.579Z,1741717647.579 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-03-11T18:27:27.579Z,1741717647.579 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-03-11T18:27:27.580Z,1741717647.580 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-03-11T18:27:27.580Z,1741717647.580 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-03-11T18:27:27.580Z,1741717647.580 [BuoyancyServo](INFO): Powering down 2025-03-11T18:27:27.592Z,1741717647.592 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-03-11T18:27:27.592Z,1741717647.592 [ElevatorServo](INFO): Powering down 2025-03-11T18:27:27.593Z,1741717647.593 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-03-11T18:27:27.593Z,1741717647.593 [MassServo](INFO): Powering down 2025-03-11T18:27:27.594Z,1741717647.594 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-03-11T18:27:27.594Z,1741717647.594 [RudderServo](INFO): Powering down 2025-03-11T18:27:27.594Z,1741717647.594 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-03-11T18:27:27.595Z,1741717647.595 [ThrusterHE](INFO): Powering down 2025-03-11T18:27:27.595Z,1741717647.595 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-03-11T18:27:27.596Z,1741717647.596 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-03-11T18:27:27.596Z,1741717647.596 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-03-11T18:27:27.596Z,1741717647.596 [CBIT](DEBUG): Powering off loads. 2025-03-11T18:27:27.607Z,1741717647.607 [CBIT](DEBUG): Disabling WDT. 2025-03-11T18:27:27.620Z,1741717647.620 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-03-11T18:27:27.620Z,1741717647.620 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-03-11T18:27:27.621Z,1741717647.621 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.789Z,1741717647.789 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.792Z,1741717647.792 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.799Z,1741717647.799 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.805Z,1741717647.805 [DAT ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.885Z,1741717647.885 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.889Z,1741717647.889 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:27.918Z,1741717647.918 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-03-11T18:27:27.918Z,1741717647.918 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-03-11T18:27:27.941Z,1741717647.941 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-11T18:27:28.021Z,1741717648.021 [logger ThreadHandler](INFO): Thread cancelled.