2025-08-11T15:49:06.230Z,1754927346.230 [Supervisor](DEBUG): Initializing supervisor.
2025-08-11T15:49:06.235Z,1754927346.235 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-08-11T15:49:06.236Z,1754927346.236 [SyncHandler](INFO): Protected caller Thread ID is 1028
2025-08-11T15:49:06.236Z,1754927346.236 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-08-11T15:49:06.237Z,1754927346.237 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-08-11T15:49:06.238Z,1754927346.238 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1029
2025-08-11T15:49:06.242Z,1754927346.242 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-08-11T15:49:06.263Z,1754927346.263 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-08-11T15:49:06.264Z,1754927346.264 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-08-11T15:49:06.264Z,1754927346.264 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1030
2025-08-11T15:49:06.269Z,1754927346.269 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-08-11T15:49:06.270Z,1754927346.270 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-08-11T15:49:06.270Z,1754927346.270 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1031
2025-08-11T15:49:06.272Z,1754927346.272 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-08-11T15:49:06.273Z,1754927346.273 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-08-11T15:49:06.274Z,1754927346.274 [logger ThreadHandler](INFO): Protected caller Thread ID is 1032
2025-08-11T15:49:06.278Z,1754927346.278 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-08-11T15:49:06.278Z,1754927346.278 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-08-11T15:49:06.280Z,1754927346.280 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-08-11T15:49:06.549Z,1754927346.549 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-08-11T15:49:06.549Z,1754927346.549 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-08-11T15:49:06.648Z,1754927346.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-08-11T15:49:06.649Z,1754927346.649 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-08-11T15:49:07.175Z,1754927347.175 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-08-11T15:49:07.176Z,1754927347.176 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-08-11T15:49:07.530Z,1754927347.530 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-08-11T15:49:07.530Z,1754927347.530 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-08-11T15:49:07.635Z,1754927347.635 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-08-11T15:49:07.636Z,1754927347.636 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-08-11T15:49:08.062Z,1754927348.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-08-11T15:49:08.063Z,1754927348.063 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-08-11T15:49:08.298Z,1754927348.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-08-11T15:49:08.299Z,1754927348.299 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-08-11T15:49:08.859Z,1754927348.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-08-11T15:49:08.859Z,1754927348.859 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-08-11T15:49:09.008Z,1754927349.008 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-08-11T15:49:09.009Z,1754927349.009 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-08-11T15:49:09.098Z,1754927349.098 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-08-11T15:49:09.991Z,1754927349.991 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-08-11T15:49:09.992Z,1754927349.992 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-08-11T15:49:10.814Z,1754927350.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-08-11T15:49:10.814Z,1754927350.814 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-08-11T15:49:11.005Z,1754927351.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-08-11T15:49:11.005Z,1754927351.005 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-08-11T15:49:11.129Z,1754927351.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-08-11T15:49:11.129Z,1754927351.129 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-08-11T15:49:11.369Z,1754927351.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-08-11T15:49:11.369Z,1754927351.369 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-08-11T15:49:11.633Z,1754927351.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-08-11T15:49:11.635Z,1754927351.635 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2025-08-11T15:49:11.636Z,1754927351.636 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2025-08-11T15:49:11.730Z,1754927351.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2025-08-11T15:49:11.841Z,1754927351.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2025-08-11T15:49:11.934Z,1754927351.934 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2025-08-11T15:49:12.047Z,1754927352.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2025-08-11T15:49:12.149Z,1754927352.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2025-08-11T15:49:12.276Z,1754927352.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2025-08-11T15:49:12.434Z,1754927352.434 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2025-08-11T15:49:12.589Z,1754927352.589 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2025-08-11T15:49:12.706Z,1754927352.706 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2025-08-11T15:49:12.987Z,1754927352.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-08-11T15:49:12.987Z,1754927352.987 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-08-11T15:49:12.993Z,1754927352.993 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-08-11T15:49:13.053Z,1754927353.053 [VerticalControl](DEBUG): Construct VerticalControl.
2025-08-11T15:49:13.117Z,1754927353.117 [VerticalControl] Loaded
2025-08-11T15:49:13.118Z,1754927353.118 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-08-11T15:49:13.121Z,1754927353.121 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-08-11T15:49:13.170Z,1754927353.170 [HorizontalControl] Loaded
2025-08-11T15:49:13.171Z,1754927353.171 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-08-11T15:49:13.173Z,1754927353.173 [SpeedControl](DEBUG): Construct SpeedControl.
2025-08-11T15:49:13.176Z,1754927353.176 [SpeedControl] Loaded
2025-08-11T15:49:13.177Z,1754927353.177 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-08-11T15:49:13.179Z,1754927353.179 [LoopControl](DEBUG): Construct LoopControl.
2025-08-11T15:49:13.180Z,1754927353.180 [LoopControl] Loaded
2025-08-11T15:49:13.180Z,1754927353.180 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-08-11T15:49:13.181Z,1754927353.181 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-08-11T15:49:13.181Z,1754927353.181 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-08-11T15:49:13.192Z,1754927353.192 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-08-11T15:49:13.192Z,1754927353.192 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-08-11T15:49:13.385Z,1754927353.385 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-08-11T15:49:13.385Z,1754927353.385 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-08-11T15:49:13.554Z,1754927353.554 [BuoyancyServo] Loaded
2025-08-11T15:49:13.554Z,1754927353.554 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-08-11T15:49:13.577Z,1754927353.577 [ElevatorServo] Loaded
2025-08-11T15:49:13.578Z,1754927353.578 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-08-11T15:49:13.599Z,1754927353.599 [MassServo] Loaded
2025-08-11T15:49:13.600Z,1754927353.600 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-08-11T15:49:13.621Z,1754927353.621 [RudderServo] Loaded
2025-08-11T15:49:13.622Z,1754927353.622 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-08-11T15:49:13.639Z,1754927353.639 [ThrusterHE] Loaded
2025-08-11T15:49:13.639Z,1754927353.639 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-08-11T15:49:13.640Z,1754927353.640 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-08-11T15:49:13.640Z,1754927353.640 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-08-11T15:49:13.762Z,1754927353.762 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-08-11T15:49:13.762Z,1754927353.762 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-08-11T15:49:13.776Z,1754927353.776 [NavChart] Loaded
2025-08-11T15:49:13.777Z,1754927353.777 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-08-11T15:49:13.782Z,1754927353.782 [UniversalFixResidualReporter] Loaded
2025-08-11T15:49:13.783Z,1754927353.783 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-08-11T15:49:13.783Z,1754927353.783 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-08-11T15:49:13.784Z,1754927353.784 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-08-11T15:49:13.848Z,1754927353.848 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-08-11T15:49:13.849Z,1754927353.849 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-08-11T15:49:14.374Z,1754927354.374 [AHRS_M2] Loaded
2025-08-11T15:49:14.375Z,1754927354.375 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-08-11T15:49:15.485Z,1754927355.485 [BPC1] Loaded
2025-08-11T15:49:15.485Z,1754927355.485 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-08-11T15:49:15.765Z,1754927355.765 [DAT] Loaded
2025-08-11T15:49:15.765Z,1754927355.765 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-08-11T15:49:15.766Z,1754927355.766 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4094B4E0
2025-08-11T15:49:15.767Z,1754927355.767 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1111
2025-08-11T15:49:15.847Z,1754927355.847 [DataOverHttps] Loaded
2025-08-11T15:49:15.848Z,1754927355.848 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-08-11T15:49:15.849Z,1754927355.849 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097B4E0
2025-08-11T15:49:15.849Z,1754927355.849 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1112
2025-08-11T15:49:15.873Z,1754927355.873 [Depth_Keller] Loaded
2025-08-11T15:49:15.874Z,1754927355.874 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-08-11T15:49:15.879Z,1754927355.879 [DropWeight] Loaded
2025-08-11T15:49:15.879Z,1754927355.879 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-08-11T15:49:15.946Z,1754927355.946 [NAL9602] Loaded
2025-08-11T15:49:15.946Z,1754927355.946 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-08-11T15:49:15.977Z,1754927355.977 [Onboard] Loaded
2025-08-11T15:49:15.977Z,1754927355.977 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-08-11T15:49:15.978Z,1754927355.978 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AB4E0
2025-08-11T15:49:15.978Z,1754927355.978 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1113
2025-08-11T15:49:15.993Z,1754927355.993 [Power24vConverter] Loaded
2025-08-11T15:49:15.993Z,1754927355.993 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-08-11T15:49:16.010Z,1754927356.010 [Radio_Surface] Loaded
2025-08-11T15:49:16.010Z,1754927356.010 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-08-11T15:49:16.011Z,1754927356.011 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2025-08-11T15:49:16.012Z,1754927356.012 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1114
2025-08-11T15:49:16.028Z,1754927356.028 [Sonardyne_Nano] Loaded
2025-08-11T15:49:16.028Z,1754927356.028 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-08-11T15:49:16.029Z,1754927356.029 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-08-11T15:49:16.030Z,1754927356.030 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-08-11T15:49:16.086Z,1754927356.086 [DepthRateCalculator] Loaded
2025-08-11T15:49:16.086Z,1754927356.086 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-08-11T15:49:16.091Z,1754927356.091 [PitchRateCalculator] Loaded
2025-08-11T15:49:16.092Z,1754927356.092 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-08-11T15:49:16.101Z,1754927356.101 [SpeedCalculator] Loaded
2025-08-11T15:49:16.101Z,1754927356.101 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-08-11T15:49:16.106Z,1754927356.106 [YawRateCalculator] Loaded
2025-08-11T15:49:16.106Z,1754927356.106 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-08-11T15:49:16.126Z,1754927356.126 [ElevatorOffsetCalculator] Loaded
2025-08-11T15:49:16.127Z,1754927356.127 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-08-11T15:49:16.127Z,1754927356.127 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-08-11T15:49:16.128Z,1754927356.128 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-08-11T15:49:16.275Z,1754927356.275 [CANONSampler] Loaded
2025-08-11T15:49:16.275Z,1754927356.275 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2025-08-11T15:49:16.339Z,1754927356.339 [CTD_Seabird] Loaded
2025-08-11T15:49:16.339Z,1754927356.339 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-08-11T15:49:16.341Z,1754927356.341 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A994E0
2025-08-11T15:49:16.341Z,1754927356.341 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1115
2025-08-11T15:49:16.364Z,1754927356.364 [PAR_Licor] Loaded
2025-08-11T15:49:16.365Z,1754927356.365 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-08-11T15:49:16.412Z,1754927356.412 [WetLabsBB2FL] Loaded
2025-08-11T15:49:16.412Z,1754927356.412 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-08-11T15:49:16.413Z,1754927356.413 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC94E0
2025-08-11T15:49:16.414Z,1754927356.414 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1116
2025-08-11T15:49:16.414Z,1754927356.414 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-08-11T15:49:16.415Z,1754927356.415 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-08-11T15:49:16.446Z,1754927356.446 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-08-11T15:49:16.447Z,1754927356.447 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-08-11T15:49:16.823Z,1754927356.823 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-08-11T15:49:16.823Z,1754927356.823 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-08-11T15:49:16.000Z,1754927357.000 [SBIT](DEBUG): Construct Startup Built In Test.
2025-08-11T15:49:17.009Z,1754927357.009 [SBIT] Loaded
2025-08-11T15:49:17.010Z,1754927357.010 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-08-11T15:49:17.013Z,1754927357.013 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-08-11T15:49:17.027Z,1754927357.027 [IBIT] Loaded
2025-08-11T15:49:17.027Z,1754927357.027 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-08-11T15:49:17.033Z,1754927357.033 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-08-11T15:49:17.118Z,1754927357.118 [CBIT] Loaded
2025-08-11T15:49:17.118Z,1754927357.118 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-08-11T15:49:17.152Z,1754927357.152 [GFScanner] Loaded
2025-08-11T15:49:17.153Z,1754927357.153 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-08-11T15:49:17.153Z,1754927357.153 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-08-11T15:49:17.154Z,1754927357.154 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-08-11T15:49:17.298Z,1754927357.298 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-08-11T15:49:17.304Z,1754927357.304 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-08-11T15:49:17.308Z,1754927357.308 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-08-11T15:49:17.320Z,1754927357.320 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-08-11T15:49:17.321Z,1754927357.321 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C394E0
2025-08-11T15:49:17.321Z,1754927357.321 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1117
2025-08-11T15:49:17.326Z,1754927357.326 [Supervisor](INFO): Main Thread ID is 829
2025-08-11T15:49:17.326Z,1754927357.326 [Supervisor](DEBUG): Running supervisor.
2025-08-11T15:49:17.327Z,1754927357.327 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1118
2025-08-11T15:49:17.327Z,1754927357.327 [CommandExec](INFO): Initializing the command executive.
2025-08-11T15:49:17.329Z,1754927357.329 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1119
2025-08-11T15:49:17.331Z,1754927357.331 [controlThread ThreadHandler](INFO): Handler Thread ID is 1120
2025-08-11T15:49:17.332Z,1754927357.332 [controlThread](DEBUG): Initializing ControlThread
2025-08-11T15:49:17.333Z,1754927357.333 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-08-11T15:49:17.334Z,1754927357.334 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-08-11T15:49:17.335Z,1754927357.335 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-08-11T15:49:17.335Z,1754927357.335 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-08-11T15:49:17.337Z,1754927357.337 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-08-11T15:49:17.338Z,1754927357.338 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-08-11T15:49:17.340Z,1754927357.340 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-08-11T15:49:17.340Z,1754927357.340 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-08-11T15:49:17.341Z,1754927357.341 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-08-11T15:49:17.341Z,1754927357.341 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-08-11T15:49:17.341Z,1754927357.341 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-08-11T15:49:17.346Z,1754927357.346 [SBIT](INFO): Initialize SBIT Component.
2025-08-11T15:49:17.346Z,1754927357.346 [SBIT](IMPORTANT): git: 2025-08-11_A
2025-08-11T15:49:17.346Z,1754927357.346 [SBIT](INFO): git hash: 4b7c020c422b7eff0d6b32ea4f03df9f8397f0f0
2025-08-11T15:49:17.347Z,1754927357.347 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-08-11T15:49:17.348Z,1754927357.348 [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-08-11T15:49:17.349Z,1754927357.349 [SBIT](INFO): Beginning SBIT in 71.000000 seconds.
2025-08-11T15:49:17.349Z,1754927357.349 [IBIT](INFO): Initialize IBIT Component.
2025-08-11T15:49:17.350Z,1754927357.350 [CBIT](DEBUG): Initialize CBIT Component.
2025-08-11T15:49:17.351Z,1754927357.351 [logger ThreadHandler](INFO): Handler Thread ID is 1121
2025-08-11T15:49:17.361Z,1754927357.361 [CBIT](DEBUG): Initialized mux pins.
2025-08-11T15:49:17.361Z,1754927357.361 [CBIT](DEBUG): Initializing the watchdog timer.
2025-08-11T15:49:17.370Z,1754927357.370 [DAT ThreadHandler](INFO): Handler Thread ID is 1122
2025-08-11T15:49:17.370Z,1754927357.370 [DAT](INFO): Powering up
2025-08-11T15:49:17.371Z,1754927357.371 [DAT](DEBUG): Initializing DAT.
2025-08-11T15:49:17.375Z,1754927357.375 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1124
2025-08-11T15:49:17.377Z,1754927357.377 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-08-11T15:49:17.385Z,1754927357.385 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-08-11T15:49:17.386Z,1754927357.386 [CBIT](DEBUG): Initializing heartbeat.
2025-08-11T15:49:17.387Z,1754927357.387 [Onboard ThreadHandler](INFO): Handler Thread ID is 1125
2025-08-11T15:49:17.407Z,1754927357.407 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1126
2025-08-11T15:49:17.422Z,1754927357.422 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1127
2025-08-11T15:49:17.422Z,1754927357.422 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-08-11T15:49:17.426Z,1754927357.426 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1129
2025-08-11T15:49:17.431Z,1754927357.431 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1131
2025-08-11T15:49:17.434Z,1754927357.434 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-08-11T15:49:17.434Z,1754927357.434 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-08-11T15:49:17.434Z,1754927357.434 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-08-11T15:49:17.435Z,1754927357.435 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-08-11T15:49:17.435Z,1754927357.435 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-08-11T15:49:17.435Z,1754927357.435 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-08-11T15:49:17.435Z,1754927357.435 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-08-11T15:49:17.435Z,1754927357.435 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-08-11T15:49:17.450Z,1754927357.450 [WetLabsBB2FL](INFO): Powering up
2025-08-11T15:49:17.457Z,1754927357.457 [CBIT](DEBUG): Deactivating emergency mode.
2025-08-11T15:49:17.497Z,1754927357.497 [CBIT](DEBUG): Backplane powered.
2025-08-11T15:49:17.498Z,1754927357.498 [GFScanner](DEBUG): Initializing GFScanner
2025-08-11T15:49:17.498Z,1754927357.498 [GFScanner](DEBUG): Deactivating GF circuits.
2025-08-11T15:49:17.502Z,1754927357.502 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-08-11T15:49:17.503Z,1754927357.503 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-08-11T15:49:17.503Z,1754927357.503 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-08-11T15:49:17.504Z,1754927357.504 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-08-11T15:49:17.563Z,1754927357.563 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-08-11T15:49:17.603Z,1754927357.603 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-08-11T15:49:17.655Z,1754927357.655 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-08-11T15:49:17.656Z,1754927357.656 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-08-11T15:49:17.656Z,1754927357.656 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-08-11T15:49:17.673Z,1754927357.673 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-08-11T15:49:17.809Z,1754927357.809 [Radio_Surface](INFO): Powering up
2025-08-11T15:49:17.974Z,1754927357.974 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-08-11T15:49:17.988Z,1754927357.988 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-08-11T15:49:17.998Z,1754927357.998 [Default:A.Wait](DEBUG): Construct Wait.
2025-08-11T15:49:17.000Z,1754927358.000 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-08-11T15:49:18.034Z,1754927358.034 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-08-11T15:49:18.037Z,1754927358.037 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-08-11T15:49:18.060Z,1754927358.060 [Default:E.Execute](DEBUG): Construct Execute.
2025-08-11T15:49:18.079Z,1754927358.079 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-08-11T15:49:18.084Z,1754927358.084 [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-08-11T15:49:18.107Z,1754927358.107 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-08-11T15:49:18.170Z,1754927358.170 [Depth_Keller](INFO): Initializing.
2025-08-11T15:49:18.171Z,1754927358.171 [Power24vConverter](INFO): Powering up.
2025-08-11T15:49:18.172Z,1754927358.172 [Sonardyne_Nano](INFO): Initializing.
2025-08-11T15:49:18.186Z,1754927358.186 [CANONSampler](INFO): Powering down
2025-08-11T15:49:18.210Z,1754927358.210 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-08-11T15:49:18.236Z,1754927358.236 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-08-11T15:49:18.242Z,1754927358.242 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-08-11T15:49:18.243Z,1754927358.243 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-08-11T15:49:18.250Z,1754927358.250 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-08-11T15:49:18.250Z,1754927358.250 [MassServo](DEBUG): Initializing EZServoServo.
2025-08-11T15:49:18.258Z,1754927358.258 [MassServo](DEBUG): Initializing MassServo.
2025-08-11T15:49:18.258Z,1754927358.258 [RudderServo](DEBUG): Initializing EZServoServo.
2025-08-11T15:49:18.266Z,1754927358.266 [RudderServo](DEBUG): Initializing RudderServo.
2025-08-11T15:49:18.266Z,1754927358.266 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-08-11T15:49:18.274Z,1754927358.274 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-08-11T15:49:19.541Z,1754927359.541 [WetLabsBB2FL](INFO): Powering down
2025-08-11T15:49:20.112Z,1754927360.112 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-08-11T15:49:21.395Z,1754927361.395 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109
2025-08-11T15:49:28.966Z,1754927368.966 [DAT](INFO): DAT read:
2025-08-11T15:49:28.967Z,1754927368.967 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-08-11T15:49:30.478Z,1754927370.478 [DAT](INFO): DAT read: MF Frequency Band
2025-08-11T15:49:30.479Z,1754927370.479 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-08-11T15:49:30.480Z,1754927370.480 [DAT](INFO): DAT read: Aug 11 2025 15:49:25
2025-08-11T15:49:31.738Z,1754927371.738 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-08-11T15:49:31.739Z,1754927371.739 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2025-08-11T15:49:31.740Z,1754927371.740 [DAT](INFO): commRate: 1200
2025-08-11T15:49:33.806Z,1754927373.806 [DAT](INFO): entering command mode
2025-08-11T15:49:34.006Z,1754927374.006 [DAT](INFO): DAT read:
2025-08-11T15:49:34.007Z,1754927374.007 [DAT](INFO): DAT read: user:1>
2025-08-11T15:49:34.007Z,1754927374.007 [DAT](INFO): setting verbose to 3
2025-08-11T15:49:34.258Z,1754927374.258 [DAT](INFO): DAT read: user:1>
2025-08-11T15:49:34.259Z,1754927374.259 [DAT](INFO): DAT read: Verbose | 3
2025-08-11T15:49:34.259Z,1754927374.259 [DAT](INFO): set verbose to 3
2025-08-11T15:49:34.260Z,1754927374.260 [DAT](INFO): setting DatVerbose to 27440
2025-08-11T15:49:34.510Z,1754927374.510 [DAT](INFO): DAT read: user:2>
2025-08-11T15:49:34.511Z,1754927374.511 [DAT](INFO): DAT read: DatVerbose | 27440
2025-08-11T15:49:34.511Z,1754927374.511 [DAT](INFO): set DatVerbose to 27440
2025-08-11T15:49:34.512Z,1754927374.512 [DAT](INFO): setting transmit power to 8
2025-08-11T15:49:34.762Z,1754927374.762 [DAT](INFO): DAT read: user:3>
2025-08-11T15:49:34.763Z,1754927374.763 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-08-11T15:49:34.764Z,1754927374.764 [DAT](INFO): set transmit power to 8
2025-08-11T15:49:34.764Z,1754927374.764 [DAT](INFO): setting local address to 8
2025-08-11T15:49:35.014Z,1754927375.014 [DAT](INFO): DAT read: user:4>
2025-08-11T15:49:35.015Z,1754927375.015 [DAT](INFO): DAT read: LocalAddr | 8
2025-08-11T15:49:35.015Z,1754927375.015 [DAT](INFO): set local address to 8
2025-08-11T15:49:35.016Z,1754927375.016 [DAT](INFO): Setting time to: 15:49:35 And date to:8/11/2025
2025-08-11T15:49:35.266Z,1754927375.266 [DAT](INFO): DAT read: user:5>
2025-08-11T15:49:35.267Z,1754927375.267 [DAT](INFO): DAT read: Mon Aug 11, 2025 15:49:35
2025-08-11T15:49:35.267Z,1754927375.267 [DAT](INFO): Local DAT time set to Mon Aug 11, 2025 15:49:35
2025-08-11T15:49:45.967Z,1754927385.967 [NAL9602](INFO): Powering up NAL9602
2025-08-11T15:49:56.875Z,1754927396.875 [NAL9602](INFO): NAL9602 initialized
2025-08-11T15:50:23.539Z,1754927423.539 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:50:28.816Z,1754927428.816 [SBIT](IMPORTANT): Beginning Startup BIT
2025-08-11T15:50:28.821Z,1754927428.821 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-08-11T15:50:33.314Z,1754927433.314 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002187
CHAN A1 (24V): 0.000483
CHAN A2 (12V): -0.002476
CHAN A3 (5V): -0.001442
CHAN B0 (3.3V): 0.000576
CHAN B1 (3.15aV): -0.000369
CHAN B2 (3.15bV): 0.000093
CHAN B3 (GND): -0.000174
OPEN: -0.000267
Full Scale: +/- 1 mA
2025-08-11T15:50:34.848Z,1754927434.848 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:50:46.565Z,1754927446.565 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:50:59.087Z,1754927459.087 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:51:10.833Z,1754927470.833 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:51:22.605Z,1754927482.605 [SBIT](IMPORTANT): SBIT PASSED
2025-08-11T15:51:22.605Z,1754927482.605 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-08-11T15:51:22.606Z,1754927482.606 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter;
2025-08-11T15:51:22.606Z,1754927482.606 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;
2025-08-11T15:51:22.606Z,1754927482.606 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=251.608774 cubic_centimeter;
2025-08-11T15:51:22.606Z,1754927482.606 [SBIT](IMPORTANT): VerticalControl.massDefault=12.875968 millimeter;
2025-08-11T15:51:22.953Z,1754927482.953 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:51:22.968Z,1754927482.968 [MissionManager](IMPORTANT): Started mission Startup
2025-08-11T15:51:22.968Z,1754927482.968 [Startup] Running Loop=1
2025-08-11T15:51:22.968Z,1754927482.968 [Startup](DEBUG): Aggregate::initialize Startup
2025-08-11T15:51:22.968Z,1754927482.968 [Startup:A.GoToSurface] Running Loop=1
2025-08-11T15:51:22.968Z,1754927482.968 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-08-11T15:51:22.969Z,1754927482.969 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-08-11T15:51:22.969Z,1754927482.969 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-08-11T15:51:22.970Z,1754927482.970 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-08-11T15:51:22.970Z,1754927482.970 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-08-11T15:51:22.970Z,1754927482.970 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-08-11T15:51:22.971Z,1754927482.971 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-08-11T15:51:22.972Z,1754927482.972 [Startup:StartupSatComms] Running Loop=1
2025-08-11T15:51:22.973Z,1754927482.973 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-08-11T15:51:22.973Z,1754927482.973 [Startup:StartupSatComms:A] Running Loop=1
2025-08-11T15:51:23.384Z,1754927483.384 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-08-11T15:51:35.073Z,1754927495.073 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:52:17.506Z,1754927537.506 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-08-11T15:52:17.506Z,1754927537.506 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-08-11T15:52:17.653Z,1754927537.653 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-08-11T15:52:18.051Z,1754927538.051 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-08-11T15:52:18.051Z,1754927538.051 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-08-11T15:52:23.187Z,1754927543.187 [Startup:StartupSatComms:A](INFO): Timed out from 2025-08-11T15:51:22.0Z
2025-08-11T15:52:23.187Z,1754927543.187 [Startup:StartupSatComms:A] Stopped
2025-08-11T15:52:23.187Z,1754927543.187 [Startup:StartupSatComms:B] Running Loop=1
2025-08-11T15:52:23.595Z,1754927543.595 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-08-11T15:53:23.389Z,1754927603.389 [Startup:StartupSatComms:B](INFO): Timed out from 2025-08-11T15:52:23.2Z
2025-08-11T15:53:23.389Z,1754927603.389 [Startup:StartupSatComms:B] Stopped
2025-08-11T15:53:23.390Z,1754927603.390 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-08-11T15:53:23.390Z,1754927603.390 [Startup:StartupSatComms] Stopped
2025-08-11T15:53:23.390Z,1754927603.390 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-08-11T15:53:23.391Z,1754927603.391 [Startup](INFO): Completed Startup
2025-08-11T15:53:23.391Z,1754927603.391 [MissionManager](INFO): Startup is completed.
2025-08-11T15:53:23.391Z,1754927603.391 [MissionManager](INFO): Uninitializing Mission Startup
2025-08-11T15:53:23.391Z,1754927603.391 [Startup] Stopped
2025-08-11T15:53:23.391Z,1754927603.391 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-08-11T15:53:23.391Z,1754927603.391 [Startup:A.GoToSurface] Stopped
2025-08-11T15:53:23.391Z,1754927603.391 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-08-11T15:53:23.795Z,1754927603.795 [MissionManager](IMPORTANT): Started mission Default
2025-08-11T15:53:23.796Z,1754927603.796 [Default] Running Loop=1
2025-08-11T15:53:23.796Z,1754927603.796 [Default](DEBUG): Aggregate::initialize Default
2025-08-11T15:53:23.796Z,1754927603.796 [Default:B.GoToSurface] Running Loop=1
2025-08-11T15:53:23.796Z,1754927603.796 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-08-11T15:53:23.796Z,1754927603.796 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-08-11T15:53:23.796Z,1754927603.796 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-08-11T15:53:23.797Z,1754927603.797 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-08-11T15:53:23.797Z,1754927603.797 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-08-11T15:53:23.798Z,1754927603.798 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-08-11T15:53:23.798Z,1754927603.798 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-08-11T15:53:23.798Z,1754927603.798 [Default:A.Wait] Running Loop=1
2025-08-11T15:53:23.798Z,1754927603.798 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-08-11T15:53:37.103Z,1754927617.103 [Default:A.Wait](INFO): Done Waiting.
2025-08-11T15:53:37.103Z,1754927617.103 [Default:A.Wait] Stopped
2025-08-11T15:53:37.103Z,1754927617.103 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T15:53:37.520Z,1754927617.520 [Default:CheckIn] Running Loop=1
2025-08-11T15:53:37.520Z,1754927617.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T15:53:37.520Z,1754927617.520 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T15:53:37.921Z,1754927617.921 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-08-11T15:54:17.887Z,1754927657.887 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:54:30.845Z,1754927670.845 [NAL9602](INFO): SBD MO Status=2, MOMSN=64083, MT Status=2, MTMSN=0
2025-08-11T15:54:30.846Z,1754927670.846 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:54:31.219Z,1754927671.219 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:54:44.551Z,1754927684.551 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:54:49.812Z,1754927689.812 [NAL9602](INFO): SBD MO Status=0, MOMSN=64083, MT Status=0, MTMSN=0
2025-08-11T15:54:49.812Z,1754927689.812 [NAL9602](INFO): No messages in MT queue
2025-08-11T15:54:58.288Z,1754927698.288 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:55:12.025Z,1754927712.025 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:55:18.519Z,1754927718.519 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-08-11T15:55:18.519Z,1754927718.519 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-08-11T15:55:18.530Z,1754927718.530 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-08-11T15:55:18.925Z,1754927718.925 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-08-11T15:55:18.925Z,1754927718.925 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-08-11T15:55:25.760Z,1754927725.760 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:55:33.041Z,1754927733.041 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155531.00,A,3648.13743,N,12147.23686,W,3.110,103.87,110825,,,D*7D
2025-08-11T15:55:33.044Z,1754927733.044 [NAL9602](INFO): GPS fix at 20250811T155531: (36.802290, -121.787281)
2025-08-11T15:55:33.056Z,1754927733.056 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T15:55:33.056Z,1754927733.056 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T15:55:33.482Z,1754927733.482 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-08-11T15:55:39.097Z,1754927739.097 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:55:52.474Z,1754927752.474 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:56:03.449Z,1754927763.449 [NAL9602](INFO): SBD MO Status=2, MOMSN=64084, MT Status=2, MTMSN=0
2025-08-11T15:56:03.456Z,1754927763.456 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:56:05.808Z,1754927765.808 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:56:20.914Z,1754927780.914 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T15:56:33.784Z,1754927793.784 [NAL9602](INFO): SBD MO Status=2, MOMSN=64084, MT Status=2, MTMSN=0
2025-08-11T15:56:33.784Z,1754927793.784 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:56:59.739Z,1754927819.739 [NAL9602](INFO): SBD MO Status=2, MOMSN=64084, MT Status=2, MTMSN=0
2025-08-11T15:56:59.739Z,1754927819.739 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:57:36.109Z,1754927856.109 [NAL9602](INFO): SBD MO Status=2, MOMSN=64084, MT Status=2, MTMSN=0
2025-08-11T15:57:36.109Z,1754927856.109 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:57:53.128Z,1754927873.128 [NAL9602](INFO): SBD MO Status=2, MOMSN=64084, MT Status=2, MTMSN=0
2025-08-11T15:57:53.128Z,1754927873.128 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:58:10.540Z,1754927890.540 [NAL9602](INFO): SBD MO Status=2, MOMSN=64084, MT Status=2, MTMSN=0
2025-08-11T15:58:10.540Z,1754927890.540 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:58:46.171Z,1754927926.171 [NAL9602](INFO): SBD MO Status=1, MOMSN=64084, MT Status=0, MTMSN=0
2025-08-11T15:58:46.230Z,1754927926.230 [NAL9602](INFO): Sent 168 bytes from file Logs/20250811T150938/Courier0016.lzma
2025-08-11T15:58:46.230Z,1754927926.230 [NAL9602](INFO): Packets left to send: 0
2025-08-11T15:58:51.872Z,1754927931.872 [NAL9602](INFO): SBD MO Status=1, MOMSN=64085, MT Status=0, MTMSN=0
2025-08-11T15:58:51.930Z,1754927931.930 [NAL9602](INFO): Sent 151 bytes from file Logs/20250811T154906/Courier0000.lzma
2025-08-11T15:58:51.930Z,1754927931.930 [NAL9602](INFO): Packets left to send: 0
2025-08-11T15:59:12.516Z,1754927952.516 [NAL9602](INFO): SBD MO Status=1, MOMSN=64086, MT Status=0, MTMSN=0
2025-08-11T15:59:12.574Z,1754927952.574 [NAL9602](INFO): Sent 223 bytes from file Logs/20250811T154906/Courier0004.lzma
2025-08-11T15:59:12.574Z,1754927952.574 [NAL9602](INFO): Packets left to send: 0
2025-08-11T15:59:27.905Z,1754927967.905 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T15:59:27.905Z,1754927967.905 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T15:59:42.892Z,1754927982.892 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T15:59:42.892Z,1754927982.892 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:00:07.602Z,1754928007.602 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:00:07.602Z,1754928007.602 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:00:44.810Z,1754928044.810 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:00:44.810Z,1754928044.810 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:01:10.712Z,1754928070.712 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:01:10.712Z,1754928070.712 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:01:42.656Z,1754928102.656 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:01:42.656Z,1754928102.656 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:02:07.428Z,1754928127.428 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:02:07.428Z,1754928127.428 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:02:56.296Z,1754928176.296 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:02:56.296Z,1754928176.296 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:03:28.264Z,1754928208.264 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:03:28.264Z,1754928208.264 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:03:46.478Z,1754928226.478 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:03:56.988Z,1754928236.988 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:03:56.988Z,1754928236.988 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:03:59.405Z,1754928239.405 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:04:12.807Z,1754928252.807 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:04:25.339Z,1754928265.339 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:04:25.339Z,1754928265.339 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:04:26.541Z,1754928266.541 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:04:40.681Z,1754928280.681 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:04:54.418Z,1754928294.418 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:05:08.617Z,1754928308.617 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:05:08.617Z,1754928308.617 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:05:09.828Z,1754928309.828 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:05:23.968Z,1754928323.968 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:05:37.349Z,1754928337.349 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:05:38.977Z,1754928338.977 [NAL9602](INFO): SBD MO Status=2, MOMSN=64087, MT Status=2, MTMSN=0
2025-08-11T16:05:38.977Z,1754928338.977 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:05:45.658Z,1754928345.658 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003054
2025-08-11T16:05:50.721Z,1754928350.721 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:05:55.202Z,1754928355.202 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20250811T150938/Express0017.lzma
2025-08-11T16:05:56.203Z,1754928356.203 [DataOverHttps](INFO): Moved sent file to Logs/20250811T150938/Express0017.lzma.bak
2025-08-11T16:05:56.203Z,1754928356.203 [DataOverHttps](INFO): SBD MOMSN=25838342
2025-08-11T16:06:00.828Z,1754928360.828 [NAL9602](INFO): SBD MO Status=1, MOMSN=64087, MT Status=0, MTMSN=0
2025-08-11T16:06:00.890Z,1754928360.890 [NAL9602](INFO): Sent 213 bytes from file Logs/20250811T150938/Express0017.lzma
2025-08-11T16:06:00.890Z,1754928360.890 [NAL9602](INFO): Packets left to send: 0
2025-08-11T16:06:00.950Z,1754928360.950 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:06:00.950Z,1754928360.950 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:06:00.950Z,1754928360.950 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:06:04.457Z,1754928364.457 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:06:12.403Z,1754928372.403 [DataOverHttps](INFO): Sending 804 bytes from file Logs/20250811T154906/Express0001.lzma
2025-08-11T16:06:13.403Z,1754928373.403 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0001.lzma.bak
2025-08-11T16:06:13.403Z,1754928373.403 [DataOverHttps](INFO): SBD MOMSN=25838355
2025-08-11T16:06:31.527Z,1754928391.527 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:06:44.139Z,1754928404.139 [DataOverHttps](IMPORTANT): SBD MTMSN=20250811T160643
2025-08-11T16:06:51.686Z,1754928411.686 [DataOverHttps](INFO): Received command: ibit
2025-08-11T16:06:51.729Z,1754928411.729 [CommandExec](IMPORTANT): got command ibit
2025-08-11T16:06:51.752Z,1754928411.752 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-08-11T16:06:51.752Z,1754928411.752 [IBIT](IMPORTANT): Beginning control surface checks.
2025-08-11T16:06:51.755Z,1754928411.755 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-08-11T16:06:53.350Z,1754928413.350 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160652.00,A,3648.14702,N,12147.21774,W,0.078,295.94,110825,,,A*76
2025-08-11T16:06:53.352Z,1754928413.352 [NAL9602](INFO): GPS fix at 20250811T160652: (36.802450, -121.786962)
2025-08-11T16:06:56.369Z,1754928416.369 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002404
CHAN A1 (24V): 0.000250
CHAN A2 (12V): -0.002474
CHAN A3 (5V): -0.001380
CHAN B0 (3.3V): 0.000385
CHAN B1 (3.15aV): 0.000170
CHAN B2 (3.15bV): 0.000383
CHAN B3 (GND): -0.000459
OPEN: -0.000729
Full Scale: +/- 1 mA
2025-08-11T16:07:37.803Z,1754928457.803 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802452 Longitude: -121.786964
2025-08-11T16:07:38.213Z,1754928458.213 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2025-08-11T16:07:38.627Z,1754928458.627 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-08-11T16:07:38.627Z,1754928458.627 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-08-11T16:07:38.627Z,1754928458.627 [IBIT](IMPORTANT): Pressure:9.523854 PSI
2025-08-11T16:07:38.628Z,1754928458.628 [IBIT](IMPORTANT): Humidity:17.726774 %
2025-08-11T16:07:39.019Z,1754928459.019 [IBIT](IMPORTANT): Vehicle Pitch:0.866922 degrees
2025-08-11T16:07:39.019Z,1754928459.019 [IBIT](IMPORTANT): Vehicle Roll:6.836785 degrees
2025-08-11T16:07:39.019Z,1754928459.019 [IBIT](IMPORTANT): Vehicle Heading:207.999512 degrees
2025-08-11T16:07:39.416Z,1754928459.416 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-08-11T16:07:39.416Z,1754928459.416 [IBIT](IMPORTANT): buoyancyNeutral: 251.608780 cc
2025-08-11T16:07:39.417Z,1754928459.417 [IBIT](IMPORTANT): massDefault: 1.287597 cm
2025-08-11T16:07:39.417Z,1754928459.417 [IBIT](IMPORTANT): stopDepth: 250.000000 m
2025-08-11T16:07:39.417Z,1754928459.417 [IBIT](IMPORTANT): abortDepth: 270.000000 m
2025-08-11T16:07:39.417Z,1754928459.417 [IBIT](IMPORTANT): IBIT PASSED
2025-08-11T16:07:49.504Z,1754928469.504 [NAL9602](INFO): SBD MO Status=2, MOMSN=64088, MT Status=2, MTMSN=0
2025-08-11T16:07:49.504Z,1754928469.504 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:08:39.252Z,1754928519.252 [NAL9602](INFO): SBD MO Status=0, MOMSN=64088, MT Status=0, MTMSN=0
2025-08-11T16:08:39.252Z,1754928519.252 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:09:09.955Z,1754928549.955 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:11:01.604Z,1754928661.604 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-08-11T16:11:01.604Z,1754928661.604 [Default:CheckIn:C.Wait] Stopped
2025-08-11T16:11:01.605Z,1754928661.605 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T16:11:01.605Z,1754928661.605 [Default:CheckIn:D] Running Loop=1
2025-08-11T16:11:01.989Z,1754928661.989 [Default:CheckIn:D] Stopped
2025-08-11T16:11:01.989Z,1754928661.989 [Default:CheckIn:E] Running Loop=1
2025-08-11T16:11:02.394Z,1754928662.394 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.636552 min
2025-08-11T16:11:02.394Z,1754928662.394 [Default:CheckIn:E] Stopped
2025-08-11T16:11:02.394Z,1754928662.394 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-08-11T16:11:02.394Z,1754928662.394 [Default:CheckIn] Stopped
2025-08-11T16:11:02.394Z,1754928662.394 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-08-11T16:11:02.395Z,1754928662.395 [Default:CheckIn](INFO): Running loop #2
2025-08-11T16:11:02.395Z,1754928662.395 [Default:CheckIn] Running Loop=2
2025-08-11T16:11:02.395Z,1754928662.395 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T16:11:02.395Z,1754928662.395 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T16:11:04.472Z,1754928664.472 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161103.00,A,3648.15084,N,12147.21878,W,0.156,332.07,110825,,,A*74
2025-08-11T16:11:04.474Z,1754928664.474 [NAL9602](INFO): GPS fix at 20250811T161103: (36.802514, -121.786980)
2025-08-11T16:11:04.485Z,1754928664.485 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T16:11:04.485Z,1754928664.485 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T16:11:12.621Z,1754928672.621 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250811T154906/Courier0007.lzma
2025-08-11T16:11:13.624Z,1754928673.624 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Courier0007.lzma.bak
2025-08-11T16:11:13.625Z,1754928673.625 [DataOverHttps](INFO): SBD MOMSN=25838441
2025-08-11T16:11:30.258Z,1754928690.258 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20250811T154906/Express0005.lzma
2025-08-11T16:11:31.259Z,1754928691.259 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0005.lzma.bak
2025-08-11T16:11:31.259Z,1754928691.259 [DataOverHttps](INFO): SBD MOMSN=25838444
2025-08-11T16:11:47.703Z,1754928707.703 [DataOverHttps](INFO): Sending 886 bytes from file Logs/20250811T154906/Express0008.lzma
2025-08-11T16:11:48.703Z,1754928708.703 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0008.lzma.bak
2025-08-11T16:11:48.703Z,1754928708.703 [DataOverHttps](INFO): SBD MOMSN=25838447
2025-08-11T16:12:05.225Z,1754928725.225 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250811T154906/Express0011.lzma
2025-08-11T16:12:06.227Z,1754928726.227 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0011.lzma.bak
2025-08-11T16:12:06.227Z,1754928726.227 [DataOverHttps](INFO): SBD MOMSN=25838473
2025-08-11T16:12:07.460Z,1754928727.460 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:12:07.461Z,1754928727.461 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:12:07.461Z,1754928727.461 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:12:37.744Z,1754928757.744 [NAL9602](INFO): SBD MO Status=2, MOMSN=64089, MT Status=2, MTMSN=0
2025-08-11T16:12:37.745Z,1754928757.745 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:13:03.612Z,1754928783.612 [NAL9602](INFO): SBD MO Status=2, MOMSN=64089, MT Status=2, MTMSN=0
2025-08-11T16:13:03.612Z,1754928783.612 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:13:18.615Z,1754928798.615 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2025-08-11T16:13:20.567Z,1754928800.567 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:13:33.897Z,1754928813.897 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:13:39.964Z,1754928819.964 [NAL9602](INFO): SBD MO Status=2, MOMSN=64089, MT Status=2, MTMSN=0
2025-08-11T16:13:39.964Z,1754928819.964 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:13:46.311Z,1754928826.311 [DataOverHttps](IMPORTANT): SBD MTMSN=20250811T161345
2025-08-11T16:13:47.229Z,1754928827.229 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:13:53.929Z,1754928833.929 [DataOverHttps](INFO): Received command: failc
2025-08-11T16:13:54.027Z,1754928834.027 [CommandExec](IMPORTANT): got command failComponent
2025-08-11T16:13:54.027Z,1754928834.027 [CommandExec](IMPORTANT): Failed components:
2025-08-11T16:13:54.027Z,1754928834.027 [CommandExec](IMPORTANT): No failed Components.
2025-08-11T16:14:00.967Z,1754928840.967 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:14:14.701Z,1754928854.701 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:14:28.526Z,1754928868.526 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:14:30.148Z,1754928870.148 [NAL9602](INFO): SBD MO Status=2, MOMSN=64089, MT Status=2, MTMSN=0
2025-08-11T16:14:30.148Z,1754928870.148 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:14:41.857Z,1754928881.857 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:14:49.133Z,1754928889.133 [NAL9602](INFO): SBD MO Status=0, MOMSN=64089, MT Status=0, MTMSN=0
2025-08-11T16:14:49.133Z,1754928889.133 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:14:55.190Z,1754928895.190 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:15:08.927Z,1754928908.927 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:15:19.895Z,1754928919.895 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:15:22.259Z,1754928922.259 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:15:35.589Z,1754928935.589 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-08-11T16:16:19.227Z,1754928979.227 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-08-11T16:16:28.591Z,1754928988.591 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2025-08-11T16:17:08.166Z,1754929028.166 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-08-11T16:17:08.166Z,1754929028.166 [Default:CheckIn:C.Wait] Stopped
2025-08-11T16:17:08.166Z,1754929028.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T16:17:08.166Z,1754929028.166 [Default:CheckIn:D] Running Loop=1
2025-08-11T16:17:08.578Z,1754929028.578 [Default:CheckIn:D] Stopped
2025-08-11T16:17:08.579Z,1754929028.579 [Default:CheckIn:E] Running Loop=1
2025-08-11T16:17:08.994Z,1754929028.994 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.746379 min
2025-08-11T16:17:08.994Z,1754929028.994 [Default:CheckIn:E] Stopped
2025-08-11T16:17:08.994Z,1754929028.994 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-08-11T16:17:08.994Z,1754929028.994 [Default:CheckIn] Stopped
2025-08-11T16:17:08.994Z,1754929028.994 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-08-11T16:17:08.995Z,1754929028.995 [Default:CheckIn](INFO): Running loop #3
2025-08-11T16:17:08.995Z,1754929028.995 [Default:CheckIn] Running Loop=3
2025-08-11T16:17:08.995Z,1754929028.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T16:17:08.995Z,1754929028.995 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T16:17:10.977Z,1754929030.977 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161710.00,A,3648.15070,N,12147.21880,W,0.058,332.07,110825,,,A*73
2025-08-11T16:17:10.979Z,1754929030.979 [NAL9602](INFO): GPS fix at 20250811T161710: (36.802512, -121.786980)
2025-08-11T16:17:10.990Z,1754929030.990 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T16:17:10.990Z,1754929030.990 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T16:17:19.090Z,1754929039.090 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250811T154906/Courier0013.lzma
2025-08-11T16:17:20.092Z,1754929040.092 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Courier0013.lzma.bak
2025-08-11T16:17:20.092Z,1754929040.092 [DataOverHttps](INFO): SBD MOMSN=25838587
2025-08-11T16:17:25.928Z,1754929045.928 [NAL9602](INFO): SBD MO Status=0, MOMSN=64090, MT Status=0, MTMSN=0
2025-08-11T16:17:25.928Z,1754929045.928 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:17:36.478Z,1754929056.478 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20250811T154906/Express0014.lzma
2025-08-11T16:17:37.471Z,1754929057.471 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0014.lzma.bak
2025-08-11T16:17:37.471Z,1754929057.471 [DataOverHttps](INFO): SBD MOMSN=25838590
2025-08-11T16:17:54.093Z,1754929074.093 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250811T154906/Express0017.lzma
2025-08-11T16:17:55.095Z,1754929075.095 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0017.lzma.bak
2025-08-11T16:17:55.095Z,1754929075.095 [DataOverHttps](INFO): SBD MOMSN=25838598
2025-08-11T16:17:56.287Z,1754929076.287 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:17:56.287Z,1754929076.287 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:17:56.287Z,1754929076.287 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:17:56.633Z,1754929076.633 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:20:18.435Z,1754929218.435 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 6.
2025-08-11T16:20:18.439Z,1754929218.439 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2025-08-11T16:22:56.813Z,1754929376.813 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-08-11T16:22:56.813Z,1754929376.813 [Default:CheckIn:C.Wait] Stopped
2025-08-11T16:22:56.814Z,1754929376.814 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T16:22:56.814Z,1754929376.814 [Default:CheckIn:D] Running Loop=1
2025-08-11T16:22:57.219Z,1754929377.219 [Default:CheckIn:D] Stopped
2025-08-11T16:22:57.219Z,1754929377.219 [Default:CheckIn:E] Running Loop=1
2025-08-11T16:22:57.629Z,1754929377.629 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.557050 min
2025-08-11T16:22:57.629Z,1754929377.629 [Default:CheckIn:E] Stopped
2025-08-11T16:22:57.630Z,1754929377.630 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-08-11T16:22:57.630Z,1754929377.630 [Default:CheckIn] Stopped
2025-08-11T16:22:57.630Z,1754929377.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-08-11T16:22:57.630Z,1754929377.630 [Default:CheckIn](INFO): Running loop #4
2025-08-11T16:22:57.630Z,1754929377.630 [Default:CheckIn] Running Loop=4
2025-08-11T16:22:57.630Z,1754929377.630 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T16:22:57.630Z,1754929377.630 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T16:22:59.632Z,1754929379.632 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162258.00,A,3648.15205,N,12147.22002,W,0.019,332.07,110825,,,A*7D
2025-08-11T16:22:59.635Z,1754929379.635 [NAL9602](INFO): GPS fix at 20250811T162258: (36.802534, -121.787000)
2025-08-11T16:22:59.647Z,1754929379.647 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T16:22:59.647Z,1754929379.647 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T16:23:07.078Z,1754929387.078 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20250811T154906/Courier0019.lzma
2025-08-11T16:23:08.079Z,1754929388.079 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Courier0019.lzma.bak
2025-08-11T16:23:08.079Z,1754929388.079 [DataOverHttps](INFO): SBD MOMSN=25838600
2025-08-11T16:23:24.593Z,1754929404.593 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250811T154906/Express0020.lzma
2025-08-11T16:23:25.596Z,1754929405.596 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0020.lzma.bak
2025-08-11T16:23:25.596Z,1754929405.596 [DataOverHttps](INFO): SBD MOMSN=25838603
2025-08-11T16:23:26.730Z,1754929406.730 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:23:26.730Z,1754929406.730 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:23:26.730Z,1754929406.730 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:23:53.364Z,1754929433.364 [NAL9602](INFO): SBD MO Status=2, MOMSN=64091, MT Status=2, MTMSN=0
2025-08-11T16:23:53.364Z,1754929433.364 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:24:18.008Z,1754929458.008 [NAL9602](INFO): SBD MO Status=2, MOMSN=64091, MT Status=2, MTMSN=0
2025-08-11T16:24:18.008Z,1754929458.008 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:24:40.228Z,1754929480.228 [NAL9602](INFO): SBD MO Status=0, MOMSN=64091, MT Status=0, MTMSN=0
2025-08-11T16:24:40.228Z,1754929480.228 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:25:10.930Z,1754929510.930 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:28:27.284Z,1754929707.284 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-08-11T16:28:27.285Z,1754929707.285 [Default:CheckIn:C.Wait] Stopped
2025-08-11T16:28:27.285Z,1754929707.285 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T16:28:27.285Z,1754929707.285 [Default:CheckIn:D] Running Loop=1
2025-08-11T16:28:27.695Z,1754929707.695 [Default:CheckIn:D] Stopped
2025-08-11T16:28:27.695Z,1754929707.695 [Default:CheckIn:E] Running Loop=1
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.064982 min
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn:E] Stopped
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn] Stopped
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn](INFO): Running loop #5
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn] Running Loop=5
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T16:28:28.095Z,1754929708.095 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T16:28:30.115Z,1754929710.115 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162829.00,A,3648.15323,N,12147.21920,W,0.447,332.07,110825,,,A*71
2025-08-11T16:28:30.117Z,1754929710.117 [NAL9602](INFO): GPS fix at 20250811T162829: (36.802554, -121.786987)
2025-08-11T16:28:30.128Z,1754929710.128 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T16:28:30.128Z,1754929710.128 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T16:28:38.129Z,1754929718.129 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250811T154906/Courier0022.lzma
2025-08-11T16:28:39.131Z,1754929719.131 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Courier0022.lzma.bak
2025-08-11T16:28:39.131Z,1754929719.131 [DataOverHttps](INFO): SBD MOMSN=25838657
2025-08-11T16:28:45.064Z,1754929725.064 [NAL9602](INFO): SBD MO Status=2, MOMSN=64092, MT Status=2, MTMSN=0
2025-08-11T16:28:45.064Z,1754929725.064 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:28:55.222Z,1754929735.222 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250811T154906/Express0023.lzma
2025-08-11T16:28:56.223Z,1754929736.223 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0023.lzma.bak
2025-08-11T16:28:56.223Z,1754929736.223 [DataOverHttps](INFO): SBD MOMSN=25838660
2025-08-11T16:28:57.602Z,1754929737.602 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:28:57.602Z,1754929737.602 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:28:57.602Z,1754929737.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:29:02.841Z,1754929742.841 [NAL9602](INFO): SBD MO Status=2, MOMSN=64092, MT Status=2, MTMSN=0
2025-08-11T16:29:02.841Z,1754929742.841 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-08-11T16:29:30.712Z,1754929770.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=64092, MT Status=0, MTMSN=0
2025-08-11T16:29:30.712Z,1754929770.712 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:30:01.414Z,1754929801.414 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:33:58.184Z,1754930038.184 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-08-11T16:33:58.184Z,1754930038.184 [Default:CheckIn:C.Wait] Stopped
2025-08-11T16:33:58.185Z,1754930038.185 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T16:33:58.185Z,1754930038.185 [Default:CheckIn:D] Running Loop=1
2025-08-11T16:33:58.589Z,1754930038.589 [Default:CheckIn:D] Stopped
2025-08-11T16:33:58.589Z,1754930038.589 [Default:CheckIn:E] Running Loop=1
2025-08-11T16:33:58.996Z,1754930038.996 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.579883 min
2025-08-11T16:33:58.996Z,1754930038.996 [Default:CheckIn:E] Stopped
2025-08-11T16:33:58.996Z,1754930038.996 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-08-11T16:33:58.996Z,1754930038.996 [Default:CheckIn] Stopped
2025-08-11T16:33:58.996Z,1754930038.996 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-08-11T16:33:58.997Z,1754930038.997 [Default:CheckIn](INFO): Running loop #6
2025-08-11T16:33:58.997Z,1754930038.997 [Default:CheckIn] Running Loop=6
2025-08-11T16:33:58.997Z,1754930038.997 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T16:33:58.997Z,1754930038.997 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T16:34:01.000Z,1754930041.000 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163400.00,A,3648.52696,N,12147.13426,W,6.143,320.81,110825,,,A*7F
2025-08-11T16:34:01.002Z,1754930041.002 [NAL9602](INFO): GPS fix at 20250811T163400: (36.808783, -121.785571)
2025-08-11T16:34:01.014Z,1754930041.014 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T16:34:01.014Z,1754930041.014 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T16:34:08.553Z,1754930048.553 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250811T154906/Courier0025.lzma
2025-08-11T16:34:09.555Z,1754930049.555 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Courier0025.lzma.bak
2025-08-11T16:34:09.555Z,1754930049.555 [DataOverHttps](INFO): SBD MOMSN=25838676
2025-08-11T16:34:10.692Z,1754930050.692 [NAL9602](INFO): SBD MO Status=0, MOMSN=64093, MT Status=0, MTMSN=0
2025-08-11T16:34:10.692Z,1754930050.692 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:34:28.522Z,1754930068.522 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250811T154906/Express0026.lzma
2025-08-11T16:34:29.499Z,1754930069.499 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0026.lzma.bak
2025-08-11T16:34:29.499Z,1754930069.499 [DataOverHttps](INFO): SBD MOMSN=25838685
2025-08-11T16:34:30.546Z,1754930070.546 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:34:30.547Z,1754930070.547 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:34:30.547Z,1754930070.547 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:34:41.450Z,1754930081.450 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:39:31.128Z,1754930371.128 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-08-11T16:39:31.129Z,1754930371.129 [Default:CheckIn:C.Wait] Stopped
2025-08-11T16:39:31.129Z,1754930371.129 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T16:39:31.129Z,1754930371.129 [Default:CheckIn:D] Running Loop=1
2025-08-11T16:39:31.528Z,1754930371.528 [Default:CheckIn:D] Stopped
2025-08-11T16:39:31.529Z,1754930371.529 [Default:CheckIn:E] Running Loop=1
2025-08-11T16:39:31.942Z,1754930371.942 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.128878 min
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn:E] Stopped
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn] Stopped
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn](INFO): Running loop #7
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn] Running Loop=7
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T16:39:31.943Z,1754930371.943 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T16:39:33.944Z,1754930373.944 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163933.00,A,3648.07044,N,12149.16448,W,30.810,258.37,110825,,,A*41
2025-08-11T16:39:33.947Z,1754930373.947 [NAL9602](INFO): GPS fix at 20250811T163933: (36.801174, -121.819408)
2025-08-11T16:39:33.981Z,1754930373.981 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T16:39:33.981Z,1754930373.981 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T16:39:41.343Z,1754930381.343 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250811T154906/Courier0028.lzma
2025-08-11T16:39:42.339Z,1754930382.339 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Courier0028.lzma.bak
2025-08-11T16:39:42.339Z,1754930382.339 [DataOverHttps](INFO): SBD MOMSN=25838743
2025-08-11T16:39:58.301Z,1754930398.301 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250811T154906/Express0029.lzma
2025-08-11T16:39:59.303Z,1754930399.303 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0029.lzma.bak
2025-08-11T16:39:59.303Z,1754930399.303 [DataOverHttps](INFO): SBD MOMSN=25838747
2025-08-11T16:40:00.621Z,1754930400.621 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:40:00.621Z,1754930400.621 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:40:00.621Z,1754930400.621 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:40:02.624Z,1754930402.624 [NAL9602](INFO): SBD MO Status=0, MOMSN=64094, MT Status=0, MTMSN=0
2025-08-11T16:40:02.624Z,1754930402.624 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:40:33.326Z,1754930433.326 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:45:01.192Z,1754930701.192 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-08-11T16:45:01.192Z,1754930701.192 [Default:CheckIn:C.Wait] Stopped
2025-08-11T16:45:01.193Z,1754930701.193 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-08-11T16:45:01.193Z,1754930701.193 [Default:CheckIn:D] Running Loop=1
2025-08-11T16:45:01.601Z,1754930701.601 [Default:CheckIn:D] Stopped
2025-08-11T16:45:01.601Z,1754930701.601 [Default:CheckIn:E] Running Loop=1
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.630086 min
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn:E] Stopped
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn] Stopped
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn](INFO): Running loop #8
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn] Running Loop=8
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-08-11T16:45:02.006Z,1754930702.006 [Default:CheckIn:Read_GPS] Running Loop=1
2025-08-11T16:45:04.013Z,1754930704.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164503.00,A,3647.81143,N,12150.93937,W,0.117,280.41,110825,,,A*77
2025-08-11T16:45:04.015Z,1754930704.015 [NAL9602](INFO): GPS fix at 20250811T164503: (36.796857, -121.848990)
2025-08-11T16:45:04.045Z,1754930704.045 [Default:CheckIn:Read_GPS] Stopped
2025-08-11T16:45:04.045Z,1754930704.045 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-08-11T16:45:11.849Z,1754930711.849 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250811T154906/Courier0031.lzma
2025-08-11T16:45:12.851Z,1754930712.851 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Courier0031.lzma.bak
2025-08-11T16:45:12.851Z,1754930712.851 [DataOverHttps](INFO): SBD MOMSN=25838765
2025-08-11T16:45:13.712Z,1754930713.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=64095, MT Status=0, MTMSN=0
2025-08-11T16:45:13.712Z,1754930713.712 [NAL9602](INFO): No messages in MT queue
2025-08-11T16:45:28.781Z,1754930728.781 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250811T154906/Express0032.lzma
2025-08-11T16:45:29.783Z,1754930729.783 [DataOverHttps](INFO): Moved sent file to Logs/20250811T154906/Express0032.lzma.bak
2025-08-11T16:45:29.783Z,1754930729.783 [DataOverHttps](INFO): SBD MOMSN=25838768
2025-08-11T16:45:31.089Z,1754930731.089 [Default:CheckIn:Read_Iridium] Stopped
2025-08-11T16:45:31.089Z,1754930731.089 [Default:CheckIn:C.Wait] Running Loop=1
2025-08-11T16:45:31.089Z,1754930731.089 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-08-11T16:45:44.407Z,1754930744.407 [NAL9602](INFO): Not Powering down - fast GPS
2025-08-11T16:47:40.515Z,1754930860.515 [DataOverHttps](IMPORTANT): SBD MTMSN=20250811T164739
2025-08-11T16:47:47.965Z,1754930867.965 [DataOverHttps](INFO): Received command: restart logs