2025-04-07T16:19:26.459Z,1744042766.459 [Supervisor](DEBUG): Initializing supervisor.
2025-04-07T16:19:26.464Z,1744042766.464 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-04-07T16:19:26.464Z,1744042766.464 [SyncHandler](INFO): Protected caller Thread ID is 6194
2025-04-07T16:19:26.464Z,1744042766.464 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-04-07T16:19:26.465Z,1744042766.465 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-04-07T16:19:26.466Z,1744042766.466 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6195
2025-04-07T16:19:26.470Z,1744042766.470 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-04-07T16:19:26.490Z,1744042766.490 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-04-07T16:19:26.491Z,1744042766.491 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-04-07T16:19:26.491Z,1744042766.491 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6196
2025-04-07T16:19:26.495Z,1744042766.495 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-04-07T16:19:26.496Z,1744042766.496 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-04-07T16:19:26.497Z,1744042766.497 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6197
2025-04-07T16:19:26.499Z,1744042766.499 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-04-07T16:19:26.500Z,1744042766.500 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-04-07T16:19:26.500Z,1744042766.500 [logger ThreadHandler](INFO): Protected caller Thread ID is 6198
2025-04-07T16:19:26.504Z,1744042766.504 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-04-07T16:19:26.504Z,1744042766.504 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-04-07T16:19:26.506Z,1744042766.506 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-04-07T16:19:26.777Z,1744042766.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-04-07T16:19:26.778Z,1744042766.778 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-04-07T16:19:26.869Z,1744042766.869 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-04-07T16:19:27.397Z,1744042767.397 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-04-07T16:19:27.397Z,1744042767.397 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-04-07T16:19:27.745Z,1744042767.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-04-07T16:19:27.746Z,1744042767.746 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-04-07T16:19:27.853Z,1744042767.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-04-07T16:19:27.854Z,1744042767.854 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-04-07T16:19:28.278Z,1744042768.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-04-07T16:19:28.279Z,1744042768.279 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-04-07T16:19:28.526Z,1744042768.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-04-07T16:19:28.527Z,1744042768.527 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-04-07T16:19:29.059Z,1744042769.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-04-07T16:19:29.060Z,1744042769.060 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-04-07T16:19:29.207Z,1744042769.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-04-07T16:19:29.208Z,1744042769.208 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-04-07T16:19:29.298Z,1744042769.298 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-04-07T16:19:30.139Z,1744042770.139 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-04-07T16:19:30.139Z,1744042770.139 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-04-07T16:19:30.523Z,1744042770.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-04-07T16:19:30.524Z,1744042770.524 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-04-07T16:19:30.726Z,1744042770.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-04-07T16:19:30.727Z,1744042770.727 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-04-07T16:19:31.160Z,1744042771.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-04-07T16:19:31.160Z,1744042771.160 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-04-07T16:19:31.559Z,1744042771.559 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-04-07T16:19:31.559Z,1744042771.559 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-04-07T16:19:31.827Z,1744042771.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-04-07T16:19:31.829Z,1744042771.829 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2025-04-07T16:19:31.830Z,1744042771.830 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2025-04-07T16:19:31.929Z,1744042771.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2025-04-07T16:19:32.043Z,1744042772.043 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2025-04-07T16:19:32.138Z,1744042772.138 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2025-04-07T16:19:32.253Z,1744042772.253 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2025-04-07T16:19:32.358Z,1744042772.358 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2025-04-07T16:19:32.488Z,1744042772.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2025-04-07T16:19:32.652Z,1744042772.652 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2025-04-07T16:19:32.821Z,1744042772.821 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2025-04-07T16:19:32.942Z,1744042772.942 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2025-04-07T16:19:33.216Z,1744042773.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-04-07T16:19:33.218Z,1744042773.218 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2025-04-07T16:19:33.218Z,1744042773.218 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-04-07T16:19:33.226Z,1744042773.226 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-04-07T16:19:33.281Z,1744042773.281 [VerticalControl](DEBUG): Construct VerticalControl.
2025-04-07T16:19:33.341Z,1744042773.341 [VerticalControl] Loaded
2025-04-07T16:19:33.342Z,1744042773.342 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-04-07T16:19:33.344Z,1744042773.344 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-04-07T16:19:33.391Z,1744042773.391 [HorizontalControl] Loaded
2025-04-07T16:19:33.391Z,1744042773.391 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-04-07T16:19:33.394Z,1744042773.394 [SpeedControl](DEBUG): Construct SpeedControl.
2025-04-07T16:19:33.397Z,1744042773.397 [SpeedControl] Loaded
2025-04-07T16:19:33.397Z,1744042773.397 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-04-07T16:19:33.400Z,1744042773.400 [LoopControl](DEBUG): Construct LoopControl.
2025-04-07T16:19:33.400Z,1744042773.400 [LoopControl] Loaded
2025-04-07T16:19:33.401Z,1744042773.401 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-04-07T16:19:33.401Z,1744042773.401 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-04-07T16:19:33.401Z,1744042773.401 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-04-07T16:19:33.412Z,1744042773.412 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-04-07T16:19:33.412Z,1744042773.412 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-04-07T16:19:33.589Z,1744042773.589 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-04-07T16:19:33.589Z,1744042773.589 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-04-07T16:19:33.746Z,1744042773.746 [BuoyancyServo] Loaded
2025-04-07T16:19:33.747Z,1744042773.747 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-04-07T16:19:33.769Z,1744042773.769 [ElevatorServo] Loaded
2025-04-07T16:19:33.769Z,1744042773.769 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-04-07T16:19:33.790Z,1744042773.790 [MassServo] Loaded
2025-04-07T16:19:33.791Z,1744042773.791 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-04-07T16:19:33.811Z,1744042773.811 [RudderServo] Loaded
2025-04-07T16:19:33.811Z,1744042773.811 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-04-07T16:19:33.828Z,1744042773.828 [ThrusterHE] Loaded
2025-04-07T16:19:33.828Z,1744042773.828 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-04-07T16:19:33.828Z,1744042773.828 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-04-07T16:19:33.829Z,1744042773.829 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-04-07T16:19:33.942Z,1744042773.942 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-04-07T16:19:33.942Z,1744042773.942 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-04-07T16:19:33.956Z,1744042773.956 [NavChart] Loaded
2025-04-07T16:19:33.956Z,1744042773.956 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-04-07T16:19:33.962Z,1744042773.962 [UniversalFixResidualReporter] Loaded
2025-04-07T16:19:33.962Z,1744042773.962 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-04-07T16:19:33.963Z,1744042773.963 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-04-07T16:19:33.963Z,1744042773.963 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-04-07T16:19:34.022Z,1744042774.022 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-04-07T16:19:34.023Z,1744042774.023 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-04-07T16:19:34.497Z,1744042774.497 [AHRS_M2] Loaded
2025-04-07T16:19:34.497Z,1744042774.497 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-04-07T16:19:35.306Z,1744042775.306 [BPC1] Loaded
2025-04-07T16:19:35.307Z,1744042775.307 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-04-07T16:19:35.406Z,1744042775.406 [DAT] Loaded
2025-04-07T16:19:35.406Z,1744042775.406 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-04-07T16:19:35.407Z,1744042775.407 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4094B4E0
2025-04-07T16:19:35.407Z,1744042775.407 [DAT ThreadHandler](INFO): Protected caller Thread ID is 6277
2025-04-07T16:19:35.481Z,1744042775.481 [DataOverHttps] Loaded
2025-04-07T16:19:35.481Z,1744042775.481 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-04-07T16:19:35.482Z,1744042775.482 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097B4E0
2025-04-07T16:19:35.482Z,1744042775.482 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6278
2025-04-07T16:19:35.505Z,1744042775.505 [Depth_Keller] Loaded
2025-04-07T16:19:35.505Z,1744042775.505 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-04-07T16:19:35.510Z,1744042775.510 [DropWeight] Loaded
2025-04-07T16:19:35.511Z,1744042775.511 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-04-07T16:19:35.574Z,1744042775.574 [NAL9602] Loaded
2025-04-07T16:19:35.575Z,1744042775.575 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-04-07T16:19:35.604Z,1744042775.604 [Onboard] Loaded
2025-04-07T16:19:35.605Z,1744042775.605 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-04-07T16:19:35.606Z,1744042775.606 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AB4E0
2025-04-07T16:19:35.606Z,1744042775.606 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6279
2025-04-07T16:19:35.620Z,1744042775.620 [Power24vConverter] Loaded
2025-04-07T16:19:35.620Z,1744042775.620 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-04-07T16:19:35.636Z,1744042775.636 [Radio_Surface] Loaded
2025-04-07T16:19:35.636Z,1744042775.636 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-04-07T16:19:35.637Z,1744042775.637 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2025-04-07T16:19:35.638Z,1744042775.638 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6280
2025-04-07T16:19:35.653Z,1744042775.653 [Sonardyne_Nano] Loaded
2025-04-07T16:19:35.653Z,1744042775.653 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-04-07T16:19:35.654Z,1744042775.654 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-04-07T16:19:35.654Z,1744042775.654 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-04-07T16:19:35.705Z,1744042775.705 [DepthRateCalculator] Loaded
2025-04-07T16:19:35.706Z,1744042775.706 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-04-07T16:19:35.711Z,1744042775.711 [PitchRateCalculator] Loaded
2025-04-07T16:19:35.711Z,1744042775.711 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-04-07T16:19:35.720Z,1744042775.720 [SpeedCalculator] Loaded
2025-04-07T16:19:35.720Z,1744042775.720 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-04-07T16:19:35.724Z,1744042775.724 [YawRateCalculator] Loaded
2025-04-07T16:19:35.724Z,1744042775.724 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-04-07T16:19:35.743Z,1744042775.743 [ElevatorOffsetCalculator] Loaded
2025-04-07T16:19:35.743Z,1744042775.743 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-04-07T16:19:35.744Z,1744042775.744 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-04-07T16:19:35.744Z,1744042775.744 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-04-07T16:19:36.329Z,1744042776.329 [CANONSampler] Loaded
2025-04-07T16:19:36.329Z,1744042776.329 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2025-04-07T16:19:36.396Z,1744042776.396 [CTD_Seabird] Loaded
2025-04-07T16:19:36.396Z,1744042776.396 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-04-07T16:19:36.397Z,1744042776.397 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A964E0
2025-04-07T16:19:36.398Z,1744042776.398 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6281
2025-04-07T16:19:36.420Z,1744042776.420 [PAR_Licor] Loaded
2025-04-07T16:19:36.420Z,1744042776.420 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-04-07T16:19:36.469Z,1744042776.469 [WetLabsBB2FL] Loaded
2025-04-07T16:19:36.469Z,1744042776.469 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-04-07T16:19:36.470Z,1744042776.470 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC64E0
2025-04-07T16:19:36.471Z,1744042776.471 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6282
2025-04-07T16:19:36.471Z,1744042776.471 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-04-07T16:19:36.472Z,1744042776.472 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-04-07T16:19:36.501Z,1744042776.501 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-04-07T16:19:36.502Z,1744042776.502 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-04-07T16:19:36.849Z,1744042776.849 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-04-07T16:19:36.850Z,1744042776.850 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-04-07T16:19:37.012Z,1744042777.012 [SBIT](DEBUG): Construct Startup Built In Test.
2025-04-07T16:19:37.020Z,1744042777.020 [SBIT] Loaded
2025-04-07T16:19:37.021Z,1744042777.021 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-04-07T16:19:37.024Z,1744042777.024 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-04-07T16:19:37.036Z,1744042777.036 [IBIT] Loaded
2025-04-07T16:19:37.037Z,1744042777.037 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-04-07T16:19:37.042Z,1744042777.042 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-04-07T16:19:37.122Z,1744042777.122 [CBIT] Loaded
2025-04-07T16:19:37.123Z,1744042777.123 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-04-07T16:19:37.155Z,1744042777.155 [GFScanner] Loaded
2025-04-07T16:19:37.155Z,1744042777.155 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-04-07T16:19:37.155Z,1744042777.155 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-04-07T16:19:37.156Z,1744042777.156 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-04-07T16:19:37.288Z,1744042777.288 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-04-07T16:19:37.295Z,1744042777.295 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-04-07T16:19:37.298Z,1744042777.298 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-04-07T16:19:37.309Z,1744042777.309 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-04-07T16:19:37.310Z,1744042777.310 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0
2025-04-07T16:19:37.310Z,1744042777.310 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6283
2025-04-07T16:19:37.314Z,1744042777.314 [Supervisor](INFO): Main Thread ID is 5570
2025-04-07T16:19:37.315Z,1744042777.315 [Supervisor](DEBUG): Running supervisor.
2025-04-07T16:19:37.315Z,1744042777.315 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6284
2025-04-07T16:19:37.316Z,1744042777.316 [CommandExec](INFO): Initializing the command executive.
2025-04-07T16:19:37.317Z,1744042777.317 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6285
2025-04-07T16:19:37.321Z,1744042777.321 [controlThread ThreadHandler](INFO): Handler Thread ID is 6286
2025-04-07T16:19:37.321Z,1744042777.321 [controlThread](DEBUG): Initializing ControlThread
2025-04-07T16:19:37.322Z,1744042777.322 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-04-07T16:19:37.324Z,1744042777.324 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-04-07T16:19:37.324Z,1744042777.324 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-04-07T16:19:37.325Z,1744042777.325 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-04-07T16:19:37.327Z,1744042777.327 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-04-07T16:19:37.327Z,1744042777.327 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-04-07T16:19:37.329Z,1744042777.329 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-04-07T16:19:37.330Z,1744042777.330 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-04-07T16:19:37.330Z,1744042777.330 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-04-07T16:19:37.330Z,1744042777.330 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-04-07T16:19:37.331Z,1744042777.331 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-04-07T16:19:37.335Z,1744042777.335 [SBIT](INFO): Initialize SBIT Component.
2025-04-07T16:19:37.335Z,1744042777.335 [SBIT](IMPORTANT): git: 2025-04-02-2-g1635786d1
2025-04-07T16:19:37.336Z,1744042777.336 [SBIT](INFO): git hash: 1635786d188a1b3aba7073e6184020eb8609012e
2025-04-07T16:19:37.336Z,1744042777.336 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-04-07T16:19:37.337Z,1744042777.337 [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-04-07T16:19:37.338Z,1744042777.338 [SBIT](INFO): Beginning SBIT in 26.000000 seconds.
2025-04-07T16:19:37.339Z,1744042777.339 [IBIT](INFO): Initialize IBIT Component.
2025-04-07T16:19:37.339Z,1744042777.339 [CBIT](DEBUG): Initialize CBIT Component.
2025-04-07T16:19:37.340Z,1744042777.340 [logger ThreadHandler](INFO): Handler Thread ID is 6287
2025-04-07T16:19:37.351Z,1744042777.351 [CBIT](DEBUG): Initialized mux pins.
2025-04-07T16:19:37.351Z,1744042777.351 [CBIT](DEBUG): Initializing the watchdog timer.
2025-04-07T16:19:37.359Z,1744042777.359 [DAT ThreadHandler](INFO): Handler Thread ID is 6288
2025-04-07T16:19:37.360Z,1744042777.360 [DAT](INFO): Powering up
2025-04-07T16:19:37.360Z,1744042777.360 [DAT](DEBUG): Initializing DAT.
2025-04-07T16:19:37.364Z,1744042777.364 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6290
2025-04-07T16:19:37.366Z,1744042777.366 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-04-07T16:19:37.375Z,1744042777.375 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-04-07T16:19:37.375Z,1744042777.375 [CBIT](DEBUG): Initializing heartbeat.
2025-04-07T16:19:37.379Z,1744042777.379 [Onboard ThreadHandler](INFO): Handler Thread ID is 6291
2025-04-07T16:19:37.397Z,1744042777.397 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6292
2025-04-07T16:19:37.420Z,1744042777.420 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6293
2025-04-07T16:19:37.420Z,1744042777.420 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-04-07T16:19:37.424Z,1744042777.424 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6295
2025-04-07T16:19:37.427Z,1744042777.427 [WetLabsBB2FL](INFO): Powering up
2025-04-07T16:19:37.428Z,1744042777.428 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6297
2025-04-07T16:19:37.431Z,1744042777.431 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-04-07T16:19:37.431Z,1744042777.431 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-04-07T16:19:37.432Z,1744042777.432 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-04-07T16:19:37.432Z,1744042777.432 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-04-07T16:19:37.432Z,1744042777.432 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-04-07T16:19:37.432Z,1744042777.432 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-04-07T16:19:37.432Z,1744042777.432 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-04-07T16:19:37.432Z,1744042777.432 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-04-07T16:19:37.447Z,1744042777.447 [CBIT](DEBUG): Deactivating emergency mode.
2025-04-07T16:19:37.487Z,1744042777.487 [CBIT](DEBUG): Backplane powered.
2025-04-07T16:19:37.487Z,1744042777.487 [GFScanner](DEBUG): Initializing GFScanner
2025-04-07T16:19:37.487Z,1744042777.487 [GFScanner](DEBUG): Deactivating GF circuits.
2025-04-07T16:19:37.492Z,1744042777.492 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-04-07T16:19:37.492Z,1744042777.492 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-04-07T16:19:37.493Z,1744042777.493 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-04-07T16:19:37.494Z,1744042777.494 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-04-07T16:19:37.551Z,1744042777.551 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-04-07T16:19:37.575Z,1744042777.575 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-07T16:19:37.603Z,1744042777.603 [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-04-07T16:19:37.604Z,1744042777.604 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-04-07T16:19:37.604Z,1744042777.604 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-04-07T16:19:37.605Z,1744042777.605 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-04-07T16:19:37.803Z,1744042777.803 [Radio_Surface](INFO): Powering up
2025-04-07T16:19:37.965Z,1744042777.965 [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-04-07T16:19:37.987Z,1744042777.987 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-04-07T16:19:37.988Z,1744042777.988 [Default:A.Wait](DEBUG): Construct Wait.
2025-04-07T16:19:37.990Z,1744042777.990 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-07T16:19:38.043Z,1744042778.043 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-04-07T16:19:38.046Z,1744042778.046 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-04-07T16:19:38.068Z,1744042778.068 [Default:E.Execute](DEBUG): Construct Execute.
2025-04-07T16:19:38.079Z,1744042778.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-04-07T16:19:38.083Z,1744042778.083 [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-04-07T16:19:38.107Z,1744042778.107 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-04-07T16:19:38.163Z,1744042778.163 [Depth_Keller](INFO): Initializing.
2025-04-07T16:19:38.164Z,1744042778.164 [Power24vConverter](INFO): Powering up.
2025-04-07T16:19:38.165Z,1744042778.165 [Sonardyne_Nano](INFO): Initializing.
2025-04-07T16:19:38.183Z,1744042778.183 [CANONSampler](INFO): Powering down
2025-04-07T16:19:38.207Z,1744042778.207 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-04-07T16:19:38.234Z,1744042778.234 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:19:38.239Z,1744042778.239 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-04-07T16:19:38.240Z,1744042778.240 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:19:38.247Z,1744042778.247 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-04-07T16:19:38.248Z,1744042778.248 [MassServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:19:38.255Z,1744042778.255 [MassServo](DEBUG): Initializing MassServo.
2025-04-07T16:19:38.256Z,1744042778.256 [RudderServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:19:38.263Z,1744042778.263 [RudderServo](DEBUG): Initializing RudderServo.
2025-04-07T16:19:38.264Z,1744042778.264 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-04-07T16:19:38.271Z,1744042778.271 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-04-07T16:19:39.535Z,1744042779.535 [WetLabsBB2FL](INFO): Powering down
2025-04-07T16:19:40.113Z,1744042780.113 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-04-07T16:19:41.400Z,1744042781.400 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109
2025-04-07T16:19:48.955Z,1744042788.955 [DAT](INFO): DAT read:
2025-04-07T16:19:48.957Z,1744042788.957 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-04-07T16:19:50.468Z,1744042790.468 [DAT](INFO): DAT read: MF Frequency Band
2025-04-07T16:19:50.469Z,1744042790.469 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-04-07T16:19:50.469Z,1744042790.469 [DAT](INFO): DAT read: Apr 7 2025 16:19:45
2025-04-07T16:19:51.728Z,1744042791.728 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-04-07T16:19:51.729Z,1744042791.729 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2025-04-07T16:19:51.729Z,1744042791.729 [DAT](INFO): commRate: 1200
2025-04-07T16:19:53.795Z,1744042793.795 [DAT](INFO): entering command mode
2025-04-07T16:19:53.995Z,1744042793.995 [DAT](INFO): DAT read:
2025-04-07T16:19:53.996Z,1744042793.996 [DAT](INFO): DAT read: user:1>
2025-04-07T16:19:53.996Z,1744042793.996 [DAT](INFO): setting verbose to 3
2025-04-07T16:19:54.247Z,1744042794.247 [DAT](INFO): DAT read: user:1>
2025-04-07T16:19:54.248Z,1744042794.248 [DAT](INFO): DAT read: Verbose | 3
2025-04-07T16:19:54.249Z,1744042794.249 [DAT](INFO): set verbose to 3
2025-04-07T16:19:54.249Z,1744042794.249 [DAT](INFO): setting DatVerbose to 27440
2025-04-07T16:19:54.499Z,1744042794.499 [DAT](INFO): DAT read: user:2>
2025-04-07T16:19:54.500Z,1744042794.500 [DAT](INFO): DAT read: DatVerbose | 27440
2025-04-07T16:19:54.501Z,1744042794.501 [DAT](INFO): set DatVerbose to 27440
2025-04-07T16:19:54.501Z,1744042794.501 [DAT](INFO): setting transmit power to 8
2025-04-07T16:19:54.751Z,1744042794.751 [DAT](INFO): DAT read: user:3>
2025-04-07T16:19:54.752Z,1744042794.752 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-04-07T16:19:54.753Z,1744042794.753 [DAT](INFO): set transmit power to 8
2025-04-07T16:19:54.753Z,1744042794.753 [DAT](INFO): setting local address to 8
2025-04-07T16:19:55.003Z,1744042795.003 [DAT](INFO): DAT read: user:4>
2025-04-07T16:19:55.004Z,1744042795.004 [DAT](INFO): DAT read: LocalAddr | 8
2025-04-07T16:19:55.005Z,1744042795.005 [DAT](INFO): set local address to 8
2025-04-07T16:19:55.006Z,1744042795.006 [DAT](INFO): Setting time to: 16:19:55 And date to:4/7/2025
2025-04-07T16:19:55.255Z,1744042795.255 [DAT](INFO): DAT read: user:5>
2025-04-07T16:19:55.256Z,1744042795.256 [DAT](INFO): DAT read: Mon Apr 7, 2025 16:19:55
2025-04-07T16:19:55.257Z,1744042795.257 [DAT](INFO): Local DAT time set to Mon Apr 7, 2025 16:19:55
2025-04-07T16:20:03.997Z,1744042803.997 [SBIT](IMPORTANT): Beginning Startup BIT
2025-04-07T16:20:04.006Z,1744042804.006 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-07T16:20:06.016Z,1744042806.016 [NAL9602](INFO): Powering up NAL9602
2025-04-07T16:20:08.527Z,1744042808.527 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002667
CHAN A1 (24V): 0.000292
CHAN A2 (12V): -0.002310
CHAN A3 (5V): -0.001675
CHAN B0 (3.3V): 0.000352
CHAN B1 (3.15aV): 0.000240
CHAN B2 (3.15bV): -0.000260
CHAN B3 (GND): 0.000355
OPEN: -0.000433
Full Scale: +/- 1 mA
2025-04-07T16:20:16.912Z,1744042816.912 [NAL9602](INFO): NAL9602 initialized
2025-04-07T16:20:31.462Z,1744042831.462 [NAL9602](INFO): SBD MO Status=0, MOMSN=62753, MT Status=0, MTMSN=0
2025-04-07T16:20:31.462Z,1744042831.462 [NAL9602](INFO): No messages in MT queue
2025-04-07T16:20:32.670Z,1744042832.670 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162030.00,A,3648.15047,N,12147.22172,W,0.369,0.00,070425,,,A*79
2025-04-07T16:20:32.673Z,1744042832.673 [NAL9602](INFO): GPS fix at 20250407T162030: (36.802508, -121.787029)
2025-04-07T16:20:57.431Z,1744042857.431 [SBIT](IMPORTANT): SBIT PASSED
2025-04-07T16:20:57.431Z,1744042857.431 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-04-07T16:20:57.432Z,1744042857.432 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=11 count;
2025-04-07T16:20:57.432Z,1744042857.432 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter;
2025-04-07T16:20:57.432Z,1744042857.432 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;
2025-04-07T16:20:57.432Z,1744042857.432 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;
2025-04-07T16:20:57.432Z,1744042857.432 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;
2025-04-07T16:20:57.432Z,1744042857.432 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=228.244267 cubic_centimeter;
2025-04-07T16:20:57.433Z,1744042857.433 [SBIT](IMPORTANT): VerticalControl.massDefault=1.588040 millimeter;
2025-04-07T16:20:57.823Z,1744042857.823 [MissionManager](IMPORTANT): Started mission Startup
2025-04-07T16:20:57.824Z,1744042857.824 [Startup] Running Loop=1
2025-04-07T16:20:57.824Z,1744042857.824 [Startup](DEBUG): Aggregate::initialize Startup
2025-04-07T16:20:57.824Z,1744042857.824 [Startup:A.GoToSurface] Running Loop=1
2025-04-07T16:20:57.824Z,1744042857.824 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T16:20:57.824Z,1744042857.824 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T16:20:57.825Z,1744042857.825 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T16:20:57.825Z,1744042857.825 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T16:20:57.825Z,1744042857.825 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T16:20:57.826Z,1744042857.826 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T16:20:57.826Z,1744042857.826 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T16:20:57.828Z,1744042857.828 [Startup:StartupSatComms] Running Loop=1
2025-04-07T16:20:57.828Z,1744042857.828 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-04-07T16:20:57.828Z,1744042857.828 [Startup:StartupSatComms:A] Running Loop=1
2025-04-07T16:20:58.218Z,1744042858.218 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-04-07T16:20:59.807Z,1744042859.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162058.00,A,3648.15462,N,12147.22479,W,0.117,0.00,070425,,,A*71
2025-04-07T16:20:59.809Z,1744042859.809 [NAL9602](INFO): GPS fix at 20250407T162058: (36.802577, -121.787080)
2025-04-07T16:20:59.821Z,1744042859.821 [Startup:StartupSatComms:A] Stopped
2025-04-07T16:20:59.821Z,1744042859.821 [Startup:StartupSatComms:B] Running Loop=1
2025-04-07T16:21:00.248Z,1744042860.248 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-07T16:21:36.768Z,1744042896.769 [NAL9602](INFO): SBD MO Status=1, MOMSN=62754, MT Status=0, MTMSN=0
2025-04-07T16:21:36.825Z,1744042896.825 [NAL9602](INFO): Sent 39 bytes from file Logs/20250407T160827/Courier0010.lzma
2025-04-07T16:21:36.825Z,1744042896.825 [NAL9602](INFO): Packets left to send: 0
2025-04-07T16:21:47.462Z,1744042907.462 [NAL9602](INFO): SBD MO Status=1, MOMSN=62755, MT Status=0, MTMSN=0
2025-04-07T16:21:47.511Z,1744042907.511 [NAL9602](INFO): Sent 268 bytes from file Logs/20250407T161926/Courier0000.lzma
2025-04-07T16:21:47.511Z,1744042907.511 [NAL9602](INFO): Packets left to send: 0
2025-04-07T16:21:57.340Z,1744042917.340 [NAL9602](INFO): SBD MO Status=1, MOMSN=62756, MT Status=0, MTMSN=0
2025-04-07T16:21:57.393Z,1744042917.393 [NAL9602](INFO): Sent 332 bytes from file Logs/20250407T160827/Express0011.lzma
2025-04-07T16:21:57.393Z,1744042917.393 [NAL9602](INFO): Packets left to send: 1
2025-04-07T16:22:00.253Z,1744042920.253 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-07T16:20:59.8Z
2025-04-07T16:22:00.253Z,1744042920.253 [Startup:StartupSatComms:B] Stopped
2025-04-07T16:22:00.253Z,1744042920.253 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-04-07T16:22:00.254Z,1744042920.254 [Startup:StartupSatComms] Stopped
2025-04-07T16:22:00.254Z,1744042920.254 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-04-07T16:22:00.255Z,1744042920.255 [Startup](INFO): Completed Startup
2025-04-07T16:22:00.255Z,1744042920.255 [MissionManager](INFO): Startup is completed.
2025-04-07T16:22:00.255Z,1744042920.255 [MissionManager](INFO): Uninitializing Mission Startup
2025-04-07T16:22:00.255Z,1744042920.255 [Startup] Stopped
2025-04-07T16:22:00.255Z,1744042920.255 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-04-07T16:22:00.255Z,1744042920.255 [Startup:A.GoToSurface] Stopped
2025-04-07T16:22:00.255Z,1744042920.255 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T16:22:00.438Z,1744042920.438 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T16:22:00.438Z,1744042920.438 [Default] Running Loop=1
2025-04-07T16:22:00.438Z,1744042920.438 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T16:22:00.438Z,1744042920.438 [Default:B.GoToSurface] Running Loop=1
2025-04-07T16:22:00.438Z,1744042920.438 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T16:22:00.438Z,1744042920.438 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T16:22:00.439Z,1744042920.439 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T16:22:00.439Z,1744042920.439 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T16:22:00.439Z,1744042920.439 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T16:22:00.440Z,1744042920.440 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T16:22:00.440Z,1744042920.440 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T16:22:00.440Z,1744042920.440 [Default:A.Wait] Running Loop=1
2025-04-07T16:22:00.440Z,1744042920.440 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:22:08.899Z,1744042928.899 [NAL9602](INFO): SBD MO Status=1, MOMSN=62757, MT Status=0, MTMSN=0
2025-04-07T16:22:08.951Z,1744042928.951 [NAL9602](INFO): Sent 225 bytes from file Logs/20250407T160827/Express0011.lzma
2025-04-07T16:22:08.951Z,1744042928.951 [NAL9602](INFO): Packets left to send: 0
2025-04-07T16:22:12.939Z,1744042932.939 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2025-04-07T16:22:13.780Z,1744042933.780 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T16:22:13.780Z,1744042933.780 [Default:A.Wait] Stopped
2025-04-07T16:22:13.780Z,1744042933.780 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:22:14.160Z,1744042934.160 [Default:CheckIn] Running Loop=1
2025-04-07T16:22:14.160Z,1744042934.160 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:22:14.160Z,1744042934.160 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:22:14.565Z,1744042934.565 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-04-07T16:22:16.172Z,1744042936.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162215.00,A,3648.15468,N,12147.22478,W,0.078,0.00,070425,,,A*79
2025-04-07T16:22:16.174Z,1744042936.174 [NAL9602](INFO): GPS fix at 20250407T162215: (36.802578, -121.787080)
2025-04-07T16:22:16.185Z,1744042936.185 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:22:16.185Z,1744042936.185 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T16:22:16.608Z,1744042936.608 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-07T16:22:37.769Z,1744042957.769 [NAL9602](INFO): SBD MO Status=1, MOMSN=62758, MT Status=0, MTMSN=0
2025-04-07T16:22:37.843Z,1744042957.843 [NAL9602](INFO): Sent 73 bytes from file Logs/20250407T161926/Courier0004.lzma
2025-04-07T16:22:37.843Z,1744042957.843 [NAL9602](INFO): Packets left to send: 0
2025-04-07T16:22:57.326Z,1744042977.326 [NAL9602](INFO): SBD MO Status=1, MOMSN=62759, MT Status=0, MTMSN=0
2025-04-07T16:22:57.387Z,1744042977.387 [NAL9602](INFO): Sent 332 bytes from file Logs/20250407T161926/Express0001.lzma
2025-04-07T16:22:57.387Z,1744042977.387 [NAL9602](INFO): Packets left to send: 3
2025-04-07T16:23:13.041Z,1744042993.041 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004470
2025-04-07T16:23:18.913Z,1744042998.913 [NAL9602](INFO): SBD MO Status=1, MOMSN=62760, MT Status=0, MTMSN=0
2025-04-07T16:23:18.975Z,1744042998.975 [NAL9602](INFO): Sent 332 bytes from file Logs/20250407T161926/Express0001.lzma
2025-04-07T16:23:18.975Z,1744042998.975 [NAL9602](INFO): Packets left to send: 2
2025-04-07T16:23:19.050Z,1744042999.050 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T16:23:19.050Z,1744042999.050 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T16:23:19.050Z,1744042999.050 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:23:21.557Z,1744043001.557 [DataOverHttps](INFO): Sending 1005 bytes from file Logs/20250407T161926/Express0001.lzma
2025-04-07T16:23:22.575Z,1744043002.575 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0001.lzma.bak
2025-04-07T16:23:22.576Z,1744043002.576 [DataOverHttps](INFO): SBD MOMSN=24560745
2025-04-07T16:23:49.364Z,1744043029.364 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T16:24:20.267Z,1744043060.267 [CommandExec](IMPORTANT): got command failComponent
2025-04-07T16:24:20.268Z,1744043060.268 [CommandExec](IMPORTANT): Failed components:
2025-04-07T16:24:20.268Z,1744043060.268 [CommandExec](IMPORTANT): No failed Components.
2025-04-07T16:24:22.884Z,1744043062.884 [CommandExec](IMPORTANT): got command gfscan
2025-04-07T16:24:23.111Z,1744043063.111 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-07T16:24:27.579Z,1744043067.579 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002338
CHAN A1 (24V): 0.000213
CHAN A2 (12V): -0.002104
CHAN A3 (5V): -0.001612
CHAN B0 (3.3V): 0.000032
CHAN B1 (3.15aV): -0.000357
CHAN B2 (3.15bV): 0.000245
CHAN B3 (GND): -0.000475
OPEN: -0.000447
Full Scale: +/- 1 mA
2025-04-07T16:26:52.397Z,1744043212.397 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2025-04-07T16:28:03.883Z,1744043283.883 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T16:28:03.888Z,1744043283.888 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 5.
2025-04-07T16:28:03.911Z,1744043283.911 [BPC1](INFO): Received data from all battery sticks.
2025-04-07T16:28:19.663Z,1744043299.663 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T16:28:19.663Z,1744043299.663 [Default:CheckIn:C.Wait] Stopped
2025-04-07T16:28:19.663Z,1744043299.663 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:28:19.663Z,1744043299.663 [Default:CheckIn:D] Running Loop=1
2025-04-07T16:28:20.067Z,1744043300.067 [Default:CheckIn:D] Stopped
2025-04-07T16:28:20.068Z,1744043300.068 [Default:CheckIn:E] Running Loop=1
2025-04-07T16:28:20.475Z,1744043300.475 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.327161 min
2025-04-07T16:28:20.475Z,1744043300.475 [Default:CheckIn:E] Stopped
2025-04-07T16:28:20.475Z,1744043300.475 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T16:28:20.475Z,1744043300.475 [Default:CheckIn] Stopped
2025-04-07T16:28:20.475Z,1744043300.475 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:28:20.475Z,1744043300.475 [Default:CheckIn](INFO): Running loop #2
2025-04-07T16:28:20.475Z,1744043300.475 [Default:CheckIn] Running Loop=2
2025-04-07T16:28:20.476Z,1744043300.476 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:28:20.476Z,1744043300.476 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:28:22.486Z,1744043302.486 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162821.00,A,3648.15368,N,12147.22244,W,0.097,302.92,070425,,,D*74
2025-04-07T16:28:22.488Z,1744043302.488 [NAL9602](INFO): GPS fix at 20250407T162821: (36.802561, -121.787041)
2025-04-07T16:28:22.507Z,1744043302.507 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:28:22.507Z,1744043302.507 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T16:28:30.647Z,1744043310.647 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250407T161926/Courier0007.lzma
2025-04-07T16:28:31.648Z,1744043311.648 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0007.lzma.bak
2025-04-07T16:28:31.649Z,1744043311.649 [DataOverHttps](INFO): SBD MOMSN=24560857
2025-04-07T16:28:44.309Z,1744043324.309 [NAL9602](INFO): SBD MO Status=0, MOMSN=62761, MT Status=0, MTMSN=0
2025-04-07T16:28:44.309Z,1744043324.309 [NAL9602](INFO): No messages in MT queue
2025-04-07T16:28:47.675Z,1744043327.675 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20250407T161926/Express0005.lzma
2025-04-07T16:28:48.677Z,1744043328.677 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0005.lzma.bak
2025-04-07T16:28:48.677Z,1744043328.677 [DataOverHttps](INFO): SBD MOMSN=24560860
2025-04-07T16:29:07.775Z,1744043347.775 [DataOverHttps](INFO): Sending 428 bytes from file Logs/20250407T161926/Express0008.lzma
2025-04-07T16:29:08.776Z,1744043348.776 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0008.lzma.bak
2025-04-07T16:29:08.777Z,1744043348.777 [DataOverHttps](INFO): SBD MOMSN=24560863
2025-04-07T16:29:09.826Z,1744043349.826 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T16:29:09.826Z,1744043349.826 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T16:29:09.826Z,1744043349.826 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:29:15.072Z,1744043355.072 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T16:34:10.460Z,1744043650.460 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T16:34:10.460Z,1744043650.460 [Default:CheckIn:C.Wait] Stopped
2025-04-07T16:34:10.460Z,1744043650.460 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:34:10.460Z,1744043650.460 [Default:CheckIn:D] Running Loop=1
2025-04-07T16:34:10.850Z,1744043650.850 [Default:CheckIn:D] Stopped
2025-04-07T16:34:10.850Z,1744043650.850 [Default:CheckIn:E] Running Loop=1
2025-04-07T16:34:11.263Z,1744043651.263 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.173530 min
2025-04-07T16:34:11.263Z,1744043651.263 [Default:CheckIn:E] Stopped
2025-04-07T16:34:11.263Z,1744043651.263 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T16:34:11.263Z,1744043651.263 [Default:CheckIn] Stopped
2025-04-07T16:34:11.264Z,1744043651.264 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:34:11.264Z,1744043651.264 [Default:CheckIn](INFO): Running loop #3
2025-04-07T16:34:11.264Z,1744043651.264 [Default:CheckIn] Running Loop=3
2025-04-07T16:34:11.264Z,1744043651.264 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:34:11.264Z,1744043651.264 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:34:13.271Z,1744043653.271 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163412.00,A,3648.15587,N,12147.22728,W,0.175,302.92,070425,,,D*7C
2025-04-07T16:34:13.273Z,1744043653.273 [NAL9602](INFO): GPS fix at 20250407T163412: (36.802598, -121.787121)
2025-04-07T16:34:13.283Z,1744043653.283 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:34:13.284Z,1744043653.284 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T16:34:24.154Z,1744043664.154 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0010.lzma
2025-04-07T16:34:25.157Z,1744043665.157 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0010.lzma.bak
2025-04-07T16:34:25.157Z,1744043665.157 [DataOverHttps](INFO): SBD MOMSN=24560917
2025-04-07T16:34:27.873Z,1744043667.873 [NAL9602](INFO): SBD MO Status=0, MOMSN=62762, MT Status=0, MTMSN=0
2025-04-07T16:34:27.873Z,1744043667.873 [NAL9602](INFO): No messages in MT queue
2025-04-07T16:34:41.609Z,1744043681.609 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20250407T161926/Express0011.lzma
2025-04-07T16:34:42.549Z,1744043682.549 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0011.lzma.bak
2025-04-07T16:34:42.549Z,1744043682.549 [DataOverHttps](INFO): SBD MOMSN=24560922
2025-04-07T16:34:43.642Z,1744043683.642 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T16:34:43.642Z,1744043683.642 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T16:34:43.642Z,1744043683.642 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:34:58.616Z,1744043698.616 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T16:39:44.071Z,1744043984.071 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T16:39:44.071Z,1744043984.071 [Default:CheckIn:C.Wait] Stopped
2025-04-07T16:39:44.071Z,1744043984.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:39:44.072Z,1744043984.072 [Default:CheckIn:D] Running Loop=1
2025-04-07T16:39:44.483Z,1744043984.483 [Default:CheckIn:D] Stopped
2025-04-07T16:39:44.483Z,1744043984.483 [Default:CheckIn:E] Running Loop=1
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.734078 min
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn:E] Stopped
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn] Stopped
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn](INFO): Running loop #4
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn] Running Loop=4
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:39:44.901Z,1744043984.901 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:39:46.894Z,1744043986.894 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163946.00,A,3648.15478,N,12147.22545,W,0.156,302.92,070425,,,D*79
2025-04-07T16:39:46.896Z,1744043986.896 [NAL9602](INFO): GPS fix at 20250407T163946: (36.802580, -121.787091)
2025-04-07T16:39:46.908Z,1744043986.908 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:39:46.908Z,1744043986.908 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T16:39:54.717Z,1744043994.717 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0013.lzma
2025-04-07T16:39:55.696Z,1744043995.696 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0013.lzma.bak
2025-04-07T16:39:55.697Z,1744043995.697 [DataOverHttps](INFO): SBD MOMSN=24560971
2025-04-07T16:40:12.795Z,1744044012.795 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0014.lzma
2025-04-07T16:40:13.788Z,1744044013.788 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0014.lzma.bak
2025-04-07T16:40:13.789Z,1744044013.789 [DataOverHttps](INFO): SBD MOMSN=24560974
2025-04-07T16:40:15.200Z,1744044015.200 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T16:40:15.200Z,1744044015.200 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T16:40:15.200Z,1744044015.200 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:40:25.353Z,1744044025.353 [NAL9602](INFO): SBD MO Status=2, MOMSN=62763, MT Status=2, MTMSN=0
2025-04-07T16:40:25.353Z,1744044025.353 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T16:42:54.181Z,1744044174.181 [NAL9602](INFO): SBD MO Status=2, MOMSN=62763, MT Status=2, MTMSN=0
2025-04-07T16:42:54.182Z,1744044174.182 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T16:43:21.253Z,1744044201.253 [NAL9602](INFO): SBD MO Status=2, MOMSN=62763, MT Status=2, MTMSN=0
2025-04-07T16:43:21.254Z,1744044201.254 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T16:43:59.637Z,1744044239.637 [NAL9602](INFO): SBD MO Status=0, MOMSN=62763, MT Status=0, MTMSN=0
2025-04-07T16:43:59.637Z,1744044239.637 [NAL9602](INFO): No messages in MT queue
2025-04-07T16:44:30.388Z,1744044270.388 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T16:45:15.690Z,1744044315.690 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T16:45:15.691Z,1744044315.691 [Default:CheckIn:C.Wait] Stopped
2025-04-07T16:45:15.691Z,1744044315.691 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:45:15.691Z,1744044315.691 [Default:CheckIn:D] Running Loop=1
2025-04-07T16:45:16.130Z,1744044316.130 [Default:CheckIn:D] Stopped
2025-04-07T16:45:16.130Z,1744044316.130 [Default:CheckIn:E] Running Loop=1
2025-04-07T16:45:16.510Z,1744044316.510 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.261532 min
2025-04-07T16:45:16.510Z,1744044316.510 [Default:CheckIn:E] Stopped
2025-04-07T16:45:16.515Z,1744044316.515 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T16:45:16.515Z,1744044316.515 [Default:CheckIn] Stopped
2025-04-07T16:45:16.515Z,1744044316.515 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:45:16.515Z,1744044316.515 [Default:CheckIn](INFO): Running loop #5
2025-04-07T16:45:16.515Z,1744044316.515 [Default:CheckIn] Running Loop=5
2025-04-07T16:45:16.515Z,1744044316.515 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:45:16.515Z,1744044316.515 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:45:18.514Z,1744044318.514 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164517.00,A,3648.15667,N,12147.22910,W,0.019,296.97,070425,,,D*75
2025-04-07T16:45:18.516Z,1744044318.516 [NAL9602](INFO): GPS fix at 20250407T164517: (36.802611, -121.787152)
2025-04-07T16:45:18.527Z,1744044318.527 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:45:18.527Z,1744044318.527 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T16:45:25.498Z,1744044325.498 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0016.lzma
2025-04-07T16:45:26.500Z,1744044326.500 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0016.lzma.bak
2025-04-07T16:45:26.501Z,1744044326.501 [DataOverHttps](INFO): SBD MOMSN=24560990
2025-04-07T16:45:41.133Z,1744044341.133 [NAL9602](INFO): SBD MO Status=2, MOMSN=62764, MT Status=2, MTMSN=0
2025-04-07T16:45:41.133Z,1744044341.133 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T16:45:42.459Z,1744044342.459 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0017.lzma
2025-04-07T16:45:43.460Z,1744044343.460 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0017.lzma.bak
2025-04-07T16:45:43.461Z,1744044343.461 [DataOverHttps](INFO): SBD MOMSN=24560995
2025-04-07T16:45:44.789Z,1744044344.789 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T16:45:44.789Z,1744044344.789 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T16:45:44.789Z,1744044344.789 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:46:06.989Z,1744044366.989 [NAL9602](INFO): SBD MO Status=0, MOMSN=62764, MT Status=0, MTMSN=0
2025-04-07T16:46:06.989Z,1744044366.989 [NAL9602](INFO): No messages in MT queue
2025-04-07T16:46:37.744Z,1744044397.744 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T16:50:45.224Z,1744044645.224 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T16:50:45.224Z,1744044645.224 [Default:CheckIn:C.Wait] Stopped
2025-04-07T16:50:45.224Z,1744044645.224 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:50:45.225Z,1744044645.225 [Default:CheckIn:D] Running Loop=1
2025-04-07T16:50:45.638Z,1744044645.638 [Default:CheckIn:D] Stopped
2025-04-07T16:50:45.639Z,1744044645.639 [Default:CheckIn:E] Running Loop=1
2025-04-07T16:50:46.034Z,1744044646.034 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.753341 min
2025-04-07T16:50:46.034Z,1744044646.034 [Default:CheckIn:E] Stopped
2025-04-07T16:50:46.034Z,1744044646.034 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T16:50:46.051Z,1744044646.051 [Default:CheckIn] Stopped
2025-04-07T16:50:46.051Z,1744044646.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:50:46.051Z,1744044646.051 [Default:CheckIn](INFO): Running loop #6
2025-04-07T16:50:46.051Z,1744044646.051 [Default:CheckIn] Running Loop=6
2025-04-07T16:50:46.051Z,1744044646.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:50:46.051Z,1744044646.051 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:50:48.042Z,1744044648.042 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165047.00,A,3648.15508,N,12147.22973,W,0.078,296.97,070425,,,D*7C
2025-04-07T16:50:48.061Z,1744044648.061 [NAL9602](INFO): GPS fix at 20250407T165047: (36.802585, -121.787162)
2025-04-07T16:50:48.080Z,1744044648.080 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:50:48.080Z,1744044648.080 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T16:50:58.434Z,1744044658.434 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0019.lzma
2025-04-07T16:50:59.437Z,1744044659.437 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0019.lzma.bak
2025-04-07T16:50:59.437Z,1744044659.437 [DataOverHttps](INFO): SBD MOMSN=24561075
2025-04-07T16:51:01.957Z,1744044661.957 [NAL9602](INFO): SBD MO Status=2, MOMSN=62765, MT Status=2, MTMSN=0
2025-04-07T16:51:01.958Z,1744044661.958 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T16:51:15.427Z,1744044675.427 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T161926/Express0020.lzma
2025-04-07T16:51:16.429Z,1744044676.429 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0020.lzma.bak
2025-04-07T16:51:16.429Z,1744044676.429 [DataOverHttps](INFO): SBD MOMSN=24561078
2025-04-07T16:51:17.746Z,1744044677.746 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T16:51:17.746Z,1744044677.746 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T16:51:17.746Z,1744044677.746 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:52:12.661Z,1744044732.661 [NAL9602](INFO): SBD MO Status=2, MOMSN=62765, MT Status=2, MTMSN=0
2025-04-07T16:52:12.661Z,1744044732.661 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T16:52:30.481Z,1744044750.481 [NAL9602](INFO): SBD MO Status=2, MOMSN=62765, MT Status=2, MTMSN=0
2025-04-07T16:52:30.481Z,1744044750.481 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T16:53:30.722Z,1744044810.722 [NAL9602](INFO): SBD MO Status=0, MOMSN=62765, MT Status=0, MTMSN=0
2025-04-07T16:53:30.722Z,1744044810.722 [NAL9602](INFO): No messages in MT queue
2025-04-07T16:54:01.438Z,1744044841.438 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T16:56:18.487Z,1744044978.487 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T16:56:18.487Z,1744044978.487 [Default:CheckIn:C.Wait] Stopped
2025-04-07T16:56:18.487Z,1744044978.487 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:56:18.487Z,1744044978.487 [Default:CheckIn:D] Running Loop=1
2025-04-07T16:56:18.896Z,1744044978.896 [Default:CheckIn:D] Stopped
2025-04-07T16:56:18.897Z,1744044978.897 [Default:CheckIn:E] Running Loop=1
2025-04-07T16:56:19.317Z,1744044979.317 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.307646 min
2025-04-07T16:56:19.317Z,1744044979.317 [Default:CheckIn:E] Stopped
2025-04-07T16:56:19.317Z,1744044979.317 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T16:56:19.317Z,1744044979.317 [Default:CheckIn] Stopped
2025-04-07T16:56:19.317Z,1744044979.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:56:19.317Z,1744044979.317 [Default:CheckIn](INFO): Running loop #7
2025-04-07T16:56:19.317Z,1744044979.317 [Default:CheckIn] Running Loop=7
2025-04-07T16:56:19.318Z,1744044979.318 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:56:19.318Z,1744044979.318 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:56:21.300Z,1744044981.300 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165620.00,A,3648.15433,N,12147.22721,W,0.136,55.01,070425,,,D*42
2025-04-07T16:56:21.302Z,1744044981.302 [NAL9602](INFO): GPS fix at 20250407T165620: (36.802572, -121.787120)
2025-04-07T16:56:21.321Z,1744044981.321 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:56:21.321Z,1744044981.321 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T16:56:30.910Z,1744044990.910 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0022.lzma
2025-04-07T16:56:31.912Z,1744044991.912 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0022.lzma.bak
2025-04-07T16:56:31.913Z,1744044991.913 [DataOverHttps](INFO): SBD MOMSN=24561094
2025-04-07T16:56:35.069Z,1744044995.069 [NAL9602](INFO): SBD MO Status=0, MOMSN=62766, MT Status=0, MTMSN=0
2025-04-07T16:56:35.070Z,1744044995.070 [NAL9602](INFO): No messages in MT queue
2025-04-07T16:56:47.828Z,1744045007.828 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T161926/Express0023.lzma
2025-04-07T16:56:48.845Z,1744045008.845 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0023.lzma.bak
2025-04-07T16:56:48.845Z,1744045008.845 [DataOverHttps](INFO): SBD MOMSN=24561099
2025-04-07T16:56:50.031Z,1744045010.031 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T16:56:50.031Z,1744045010.031 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T16:56:50.031Z,1744045010.031 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:57:05.832Z,1744045025.832 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:01:50.684Z,1744045310.684 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:01:50.684Z,1744045310.684 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:01:50.684Z,1744045310.684 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:01:50.685Z,1744045310.685 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:01:51.098Z,1744045311.098 [Default:CheckIn:D] Stopped
2025-04-07T17:01:51.098Z,1744045311.098 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.844336 min
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn:E] Stopped
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn] Stopped
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn](INFO): Running loop #8
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn] Running Loop=8
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:01:51.495Z,1744045311.495 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:01:53.505Z,1744045313.505 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170152.00,A,3648.15196,N,12147.22260,W,0.058,55.01,070425,,,A*42
2025-04-07T17:01:53.508Z,1744045313.508 [NAL9602](INFO): GPS fix at 20250407T170152: (36.802533, -121.787043)
2025-04-07T17:01:53.519Z,1744045313.519 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:01:53.519Z,1744045313.519 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:02:01.070Z,1744045321.070 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0025.lzma
2025-04-07T17:02:02.072Z,1744045322.072 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0025.lzma.bak
2025-04-07T17:02:02.073Z,1744045322.073 [DataOverHttps](INFO): SBD MOMSN=24561154
2025-04-07T17:02:18.251Z,1744045338.251 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20250407T161926/Express0026.lzma
2025-04-07T17:02:19.253Z,1744045339.253 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0026.lzma.bak
2025-04-07T17:02:19.253Z,1744045339.253 [DataOverHttps](INFO): SBD MOMSN=24561158
2025-04-07T17:02:20.607Z,1744045340.607 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:02:20.607Z,1744045340.607 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:02:20.607Z,1744045340.607 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:04:06.891Z,1744045446.891 [NAL9602](INFO): SBD MO Status=2, MOMSN=62767, MT Status=2, MTMSN=0
2025-04-07T17:04:06.892Z,1744045446.892 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T17:05:19.623Z,1744045519.623 [NAL9602](INFO): SBD MO Status=2, MOMSN=62767, MT Status=2, MTMSN=0
2025-04-07T17:05:19.623Z,1744045519.623 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T17:05:50.329Z,1744045550.329 [NAL9602](INFO): SBD MO Status=0, MOMSN=62767, MT Status=0, MTMSN=0
2025-04-07T17:05:50.329Z,1744045550.329 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:06:21.032Z,1744045581.032 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:07:21.249Z,1744045641.249 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:07:21.250Z,1744045641.250 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:07:21.250Z,1744045641.250 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:07:21.250Z,1744045641.250 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:07:21.642Z,1744045641.642 [Default:CheckIn:D] Stopped
2025-04-07T17:07:21.642Z,1744045641.642 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:07:22.044Z,1744045642.044 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.353402 min
2025-04-07T17:07:22.044Z,1744045642.044 [Default:CheckIn:E] Stopped
2025-04-07T17:07:22.044Z,1744045642.044 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:07:22.044Z,1744045642.044 [Default:CheckIn] Stopped
2025-04-07T17:07:22.045Z,1744045642.045 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:07:22.045Z,1744045642.045 [Default:CheckIn](INFO): Running loop #9
2025-04-07T17:07:22.045Z,1744045642.045 [Default:CheckIn] Running Loop=9
2025-04-07T17:07:22.045Z,1744045642.045 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:07:22.045Z,1744045642.045 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:07:24.057Z,1744045644.057 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170723.00,A,3648.15339,N,12147.22338,W,0.019,55.01,070425,,,A*4C
2025-04-07T17:07:24.060Z,1744045644.060 [NAL9602](INFO): GPS fix at 20250407T170723: (36.802557, -121.787056)
2025-04-07T17:07:24.099Z,1744045644.099 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:07:24.099Z,1744045644.099 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:07:31.458Z,1744045651.458 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0028.lzma
2025-04-07T17:07:32.461Z,1744045652.461 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0028.lzma.bak
2025-04-07T17:07:32.462Z,1744045652.462 [DataOverHttps](INFO): SBD MOMSN=24561170
2025-04-07T17:07:48.463Z,1744045668.463 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250407T161926/Express0029.lzma
2025-04-07T17:07:49.465Z,1744045669.465 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0029.lzma.bak
2025-04-07T17:07:49.465Z,1744045669.465 [DataOverHttps](INFO): SBD MOMSN=24561173
2025-04-07T17:07:50.730Z,1744045670.730 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:07:50.730Z,1744045670.730 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:07:50.730Z,1744045670.730 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:07:57.997Z,1744045677.997 [NAL9602](INFO): SBD MO Status=2, MOMSN=62768, MT Status=2, MTMSN=0
2025-04-07T17:07:57.997Z,1744045677.997 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T17:08:15.774Z,1744045695.774 [NAL9602](INFO): SBD MO Status=0, MOMSN=62768, MT Status=0, MTMSN=0
2025-04-07T17:08:15.774Z,1744045695.774 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:08:46.508Z,1744045726.508 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:12:51.438Z,1744045971.438 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:12:51.438Z,1744045971.438 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:12:51.438Z,1744045971.438 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:12:51.438Z,1744045971.438 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:12:51.794Z,1744045971.794 [Default:CheckIn:D] Stopped
2025-04-07T17:12:51.794Z,1744045971.794 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:12:52.182Z,1744045972.182 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.855933 min
2025-04-07T17:12:52.182Z,1744045972.182 [Default:CheckIn:E] Stopped
2025-04-07T17:12:52.182Z,1744045972.182 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:12:52.182Z,1744045972.182 [Default:CheckIn] Stopped
2025-04-07T17:12:52.183Z,1744045972.183 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:12:52.183Z,1744045972.183 [Default:CheckIn](INFO): Running loop #10
2025-04-07T17:12:52.183Z,1744045972.183 [Default:CheckIn] Running Loop=10
2025-04-07T17:12:52.183Z,1744045972.183 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:12:52.183Z,1744045972.183 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:12:54.187Z,1744045974.187 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171253.00,A,3648.15316,N,12147.22034,W,0.117,95.17,070425,,,A*49
2025-04-07T17:12:54.189Z,1744045974.189 [NAL9602](INFO): GPS fix at 20250407T171253: (36.802553, -121.787006)
2025-04-07T17:12:54.209Z,1744045974.209 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:12:54.209Z,1744045974.209 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:13:02.586Z,1744045982.586 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0031.lzma
2025-04-07T17:13:03.588Z,1744045983.588 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0031.lzma.bak
2025-04-07T17:13:03.589Z,1744045983.589 [DataOverHttps](INFO): SBD MOMSN=24561275
2025-04-07T17:13:19.655Z,1744045999.655 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0032.lzma
2025-04-07T17:13:20.657Z,1744046000.657 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0032.lzma.bak
2025-04-07T17:13:20.657Z,1744046000.657 [DataOverHttps](INFO): SBD MOMSN=24561281
2025-04-07T17:13:21.689Z,1744046001.689 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:13:21.689Z,1744046001.689 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:13:21.689Z,1744046001.689 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:13:25.313Z,1744046005.313 [NAL9602](INFO): SBD MO Status=2, MOMSN=62769, MT Status=2, MTMSN=0
2025-04-07T17:13:25.313Z,1744046005.313 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T17:14:17.813Z,1744046057.813 [NAL9602](INFO): SBD MO Status=0, MOMSN=62769, MT Status=0, MTMSN=0
2025-04-07T17:14:17.813Z,1744046057.813 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:14:48.522Z,1744046088.522 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:18:22.269Z,1744046302.269 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:18:22.269Z,1744046302.269 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:18:22.269Z,1744046302.269 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:18:22.269Z,1744046302.269 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:18:22.680Z,1744046302.680 [Default:CheckIn:D] Stopped
2025-04-07T17:18:22.680Z,1744046302.680 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:18:23.070Z,1744046303.070 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.370345 min
2025-04-07T17:18:23.070Z,1744046303.070 [Default:CheckIn:E] Stopped
2025-04-07T17:18:23.070Z,1744046303.070 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:18:23.071Z,1744046303.071 [Default:CheckIn] Stopped
2025-04-07T17:18:23.071Z,1744046303.071 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:18:23.072Z,1744046303.072 [Default:CheckIn](INFO): Running loop #11
2025-04-07T17:18:23.072Z,1744046303.072 [Default:CheckIn] Running Loop=11
2025-04-07T17:18:23.072Z,1744046303.072 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:18:23.072Z,1744046303.072 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:18:25.078Z,1744046305.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171824.00,A,3648.15276,N,12147.22472,W,0.039,95.17,070425,,,A*4F
2025-04-07T17:18:25.080Z,1744046305.080 [NAL9602](INFO): GPS fix at 20250407T171824: (36.802546, -121.787079)
2025-04-07T17:18:25.130Z,1744046305.130 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:18:25.130Z,1744046305.130 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:18:33.106Z,1744046313.106 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0034.lzma
2025-04-07T17:18:34.108Z,1744046314.108 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0034.lzma.bak
2025-04-07T17:18:34.109Z,1744046314.109 [DataOverHttps](INFO): SBD MOMSN=24561290
2025-04-07T17:18:51.883Z,1744046331.883 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T161926/Express0035.lzma
2025-04-07T17:18:52.885Z,1744046332.885 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0035.lzma.bak
2025-04-07T17:18:52.885Z,1744046332.885 [DataOverHttps](INFO): SBD MOMSN=24561302
2025-04-07T17:18:54.202Z,1744046334.202 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:18:54.202Z,1744046334.202 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:18:54.202Z,1744046334.202 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:19:38.631Z,1744046378.631 [NAL9602](INFO): SBD MO Status=0, MOMSN=62770, MT Status=0, MTMSN=0
2025-04-07T17:19:38.632Z,1744046378.632 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:19:43.087Z,1744046383.087 [Sonardyne_Nano](INFO): Battery at maximum, disabling charging
2025-04-07T17:20:09.336Z,1744046409.336 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:23:54.798Z,1744046634.798 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:23:54.798Z,1744046634.798 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:23:54.798Z,1744046634.798 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:23:54.798Z,1744046634.798 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:23:55.198Z,1744046635.198 [Default:CheckIn:D] Stopped
2025-04-07T17:23:55.198Z,1744046635.198 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.912667 min
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn:E] Stopped
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn] Stopped
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn](INFO): Running loop #12
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn] Running Loop=12
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:23:55.596Z,1744046635.596 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:23:57.613Z,1744046637.613 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172356.00,A,3648.15283,N,12147.22424,W,0.117,95.17,070425,,,A*46
2025-04-07T17:23:57.616Z,1744046637.616 [NAL9602](INFO): GPS fix at 20250407T172356: (36.802547, -121.787071)
2025-04-07T17:23:57.626Z,1744046637.626 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:23:57.626Z,1744046637.626 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:24:04.922Z,1744046644.922 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0037.lzma
2025-04-07T17:24:05.925Z,1744046645.925 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0037.lzma.bak
2025-04-07T17:24:05.925Z,1744046645.925 [DataOverHttps](INFO): SBD MOMSN=24561357
2025-04-07T17:24:21.093Z,1744046661.093 [NAL9602](INFO): SBD MO Status=0, MOMSN=62771, MT Status=0, MTMSN=0
2025-04-07T17:24:21.093Z,1744046661.093 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:24:24.783Z,1744046664.783 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T161926/Express0038.lzma
2025-04-07T17:24:25.785Z,1744046665.785 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0038.lzma.bak
2025-04-07T17:24:25.785Z,1744046665.785 [DataOverHttps](INFO): SBD MOMSN=24561362
2025-04-07T17:24:27.176Z,1744046667.176 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:24:27.176Z,1744046667.176 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:24:27.176Z,1744046667.176 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:24:51.805Z,1744046691.805 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:29:09.998Z,1744046949.998 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:29:22.120Z,1744046962.120 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:29:27.790Z,1744046967.790 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:29:27.790Z,1744046967.790 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:29:27.790Z,1744046967.790 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:29:27.790Z,1744046967.790 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:29:28.199Z,1744046968.199 [Default:CheckIn:D] Stopped
2025-04-07T17:29:28.199Z,1744046968.199 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:29:28.602Z,1744046968.602 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.462679 min
2025-04-07T17:29:28.602Z,1744046968.602 [Default:CheckIn:E] Stopped
2025-04-07T17:29:28.602Z,1744046968.602 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:29:28.602Z,1744046968.602 [Default:CheckIn] Stopped
2025-04-07T17:29:28.603Z,1744046968.603 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:29:28.603Z,1744046968.603 [Default:CheckIn](INFO): Running loop #13
2025-04-07T17:29:28.603Z,1744046968.603 [Default:CheckIn] Running Loop=13
2025-04-07T17:29:28.604Z,1744046968.604 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:29:28.604Z,1744046968.604 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:29:30.606Z,1744046970.606 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172929.00,A,3648.15313,N,12147.22410,W,0.097,136.77,070425,,,D*79
2025-04-07T17:29:30.608Z,1744046970.608 [NAL9602](INFO): GPS fix at 20250407T172929: (36.802552, -121.787068)
2025-04-07T17:29:30.643Z,1744046970.643 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:29:30.643Z,1744046970.643 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:29:34.239Z,1744046974.239 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:29:37.882Z,1744046977.882 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0040.lzma
2025-04-07T17:29:38.885Z,1744046978.885 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0040.lzma.bak
2025-04-07T17:29:38.885Z,1744046978.885 [DataOverHttps](INFO): SBD MOMSN=24561437
2025-04-07T17:29:46.358Z,1744046986.358 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:29:55.099Z,1744046995.099 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T161926/Express0041.lzma
2025-04-07T17:29:56.101Z,1744046996.101 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0041.lzma.bak
2025-04-07T17:29:56.101Z,1744046996.101 [DataOverHttps](INFO): SBD MOMSN=24561440
2025-04-07T17:29:57.319Z,1744046997.319 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:29:57.319Z,1744046997.319 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:29:57.320Z,1744046997.320 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:29:58.478Z,1744046998.478 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:30:10.194Z,1744047010.194 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:30:21.506Z,1744047021.506 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:30:35.242Z,1744047035.242 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-04-07T17:31:03.537Z,1744047063.537 [NAL9602](INFO): SBD MO Status=0, MOMSN=62772, MT Status=0, MTMSN=0
2025-04-07T17:31:03.537Z,1744047063.537 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:31:34.244Z,1744047094.244 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:32:55.910Z,1744047175.910 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-04-07T17:33:02.727Z,1744047182.727 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:33:18.069Z,1744047198.069 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:33:33.831Z,1744047213.831 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:33:49.984Z,1744047229.984 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:34:05.335Z,1744047245.335 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:34:21.495Z,1744047261.495 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:34:36.854Z,1744047276.854 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:34:53.006Z,1744047293.006 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:34:57.878Z,1744047297.878 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:34:57.878Z,1744047297.878 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:34:57.878Z,1744047297.878 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:34:57.878Z,1744047297.878 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:34:58.287Z,1744047298.287 [Default:CheckIn:D] Stopped
2025-04-07T17:34:58.287Z,1744047298.287 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:34:58.679Z,1744047298.679 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.964152 min
2025-04-07T17:34:58.679Z,1744047298.679 [Default:CheckIn:E] Stopped
2025-04-07T17:34:58.679Z,1744047298.679 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:34:58.680Z,1744047298.680 [Default:CheckIn] Stopped
2025-04-07T17:34:58.680Z,1744047298.680 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:34:58.680Z,1744047298.680 [Default:CheckIn](INFO): Running loop #14
2025-04-07T17:34:58.680Z,1744047298.680 [Default:CheckIn] Running Loop=14
2025-04-07T17:34:58.680Z,1744047298.680 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:34:58.680Z,1744047298.680 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:35:00.691Z,1744047300.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173459.00,A,3648.15316,N,12147.22557,W,0.000,136.77,070425,,,D*7B
2025-04-07T17:35:00.693Z,1744047300.693 [NAL9602](INFO): GPS fix at 20250407T173459: (36.802553, -121.787093)
2025-04-07T17:35:00.704Z,1744047300.704 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:35:00.704Z,1744047300.704 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:35:08.522Z,1744047308.522 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0043.lzma
2025-04-07T17:35:08.765Z,1744047308.765 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T17:35:09.525Z,1744047309.525 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0043.lzma.bak
2025-04-07T17:35:09.525Z,1744047309.525 [DataOverHttps](INFO): SBD MOMSN=24561937
2025-04-07T17:35:22.505Z,1744047322.505 [NAL9602](INFO): SBD MO Status=0, MOMSN=62773, MT Status=0, MTMSN=0
2025-04-07T17:35:22.506Z,1744047322.506 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:35:25.339Z,1744047325.339 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5.
2025-04-07T17:35:25.341Z,1744047325.341 [BPC1](INFO): Received data from all battery sticks.
2025-04-07T17:35:25.598Z,1744047325.598 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0044.lzma
2025-04-07T17:35:26.601Z,1744047326.601 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0044.lzma.bak
2025-04-07T17:35:26.601Z,1744047326.601 [DataOverHttps](INFO): SBD MOMSN=24561940
2025-04-07T17:35:27.769Z,1744047327.769 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:35:27.769Z,1744047327.769 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:35:27.769Z,1744047327.769 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:35:53.204Z,1744047353.204 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:40:28.343Z,1744047628.343 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:40:28.343Z,1744047628.343 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:40:28.344Z,1744047628.344 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:40:28.344Z,1744047628.344 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:40:28.742Z,1744047628.742 [Default:CheckIn:D] Stopped
2025-04-07T17:40:28.742Z,1744047628.742 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:40:29.151Z,1744047629.151 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.471737 min
2025-04-07T17:40:29.151Z,1744047629.151 [Default:CheckIn:E] Stopped
2025-04-07T17:40:29.151Z,1744047629.151 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:40:29.151Z,1744047629.151 [Default:CheckIn] Stopped
2025-04-07T17:40:29.151Z,1744047629.151 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:40:29.151Z,1744047629.151 [Default:CheckIn](INFO): Running loop #15
2025-04-07T17:40:29.151Z,1744047629.151 [Default:CheckIn] Running Loop=15
2025-04-07T17:40:29.152Z,1744047629.152 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:40:29.152Z,1744047629.152 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:40:31.163Z,1744047631.163 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174030.00,A,3648.15203,N,12147.22406,W,0.117,136.77,070425,,,D*70
2025-04-07T17:40:31.165Z,1744047631.165 [NAL9602](INFO): GPS fix at 20250407T174030: (36.802534, -121.787068)
2025-04-07T17:40:31.183Z,1744047631.183 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:40:31.183Z,1744047631.183 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:40:39.314Z,1744047639.314 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20250407T161926/Courier0046.lzma
2025-04-07T17:40:40.317Z,1744047640.317 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0046.lzma.bak
2025-04-07T17:40:40.317Z,1744047640.317 [DataOverHttps](INFO): SBD MOMSN=24561979
2025-04-07T17:40:53.405Z,1744047653.405 [NAL9602](INFO): SBD MO Status=2, MOMSN=62774, MT Status=2, MTMSN=0
2025-04-07T17:40:53.405Z,1744047653.405 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T17:40:59.158Z,1744047659.158 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T161926/Express0047.lzma
2025-04-07T17:41:00.161Z,1744047660.161 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0047.lzma.bak
2025-04-07T17:41:00.162Z,1744047660.162 [DataOverHttps](INFO): SBD MOMSN=24561982
2025-04-07T17:41:01.529Z,1744047661.529 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:41:01.529Z,1744047661.529 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:41:01.529Z,1744047661.529 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:41:33.425Z,1744047693.425 [NAL9602](INFO): SBD MO Status=2, MOMSN=62774, MT Status=2, MTMSN=0
2025-04-07T17:41:33.425Z,1744047693.425 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T17:41:40.297Z,1744047700.297 [NAL9602](INFO): SBD MO Status=0, MOMSN=62774, MT Status=0, MTMSN=0
2025-04-07T17:41:40.297Z,1744047700.297 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:42:10.996Z,1744047730.996 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:46:02.134Z,1744047962.134 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:46:02.134Z,1744047962.134 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:46:02.134Z,1744047962.134 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:46:02.134Z,1744047962.134 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:46:02.531Z,1744047962.531 [Default:CheckIn:D] Stopped
2025-04-07T17:46:02.531Z,1744047962.531 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:46:02.938Z,1744047962.938 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.034896 min
2025-04-07T17:46:02.938Z,1744047962.938 [Default:CheckIn:E] Stopped
2025-04-07T17:46:02.938Z,1744047962.938 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:46:02.938Z,1744047962.938 [Default:CheckIn] Stopped
2025-04-07T17:46:02.938Z,1744047962.938 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:46:02.939Z,1744047962.939 [Default:CheckIn](INFO): Running loop #16
2025-04-07T17:46:02.939Z,1744047962.939 [Default:CheckIn] Running Loop=16
2025-04-07T17:46:02.939Z,1744047962.939 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:46:02.939Z,1744047962.939 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:46:04.949Z,1744047964.949 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174604.00,A,3648.15307,N,12147.22440,W,0.019,136.77,070425,,,D*79
2025-04-07T17:46:04.952Z,1744047964.952 [NAL9602](INFO): GPS fix at 20250407T174604: (36.802551, -121.787073)
2025-04-07T17:46:04.963Z,1744047964.963 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:46:04.963Z,1744047964.963 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:46:13.038Z,1744047973.038 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0049.lzma
2025-04-07T17:46:14.041Z,1744047974.041 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0049.lzma.bak
2025-04-07T17:46:14.042Z,1744047974.042 [DataOverHttps](INFO): SBD MOMSN=24562040
2025-04-07T17:46:26.399Z,1744047986.399 [NAL9602](INFO): SBD MO Status=0, MOMSN=62775, MT Status=0, MTMSN=0
2025-04-07T17:46:26.399Z,1744047986.399 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:46:33.214Z,1744047993.214 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T161926/Express0050.lzma
2025-04-07T17:46:34.217Z,1744047994.217 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0050.lzma.bak
2025-04-07T17:46:34.217Z,1744047994.217 [DataOverHttps](INFO): SBD MOMSN=24562046
2025-04-07T17:46:35.298Z,1744047995.298 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:46:35.298Z,1744047995.298 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:46:35.298Z,1744047995.298 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:46:57.104Z,1744048017.104 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:51:35.872Z,1744048295.872 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:51:35.872Z,1744048295.872 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:51:35.873Z,1744048295.873 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:51:35.873Z,1744048295.873 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:51:36.284Z,1744048296.284 [Default:CheckIn:D] Stopped
2025-04-07T17:51:36.284Z,1744048296.284 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:51:36.700Z,1744048296.700 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.597445 min
2025-04-07T17:51:36.700Z,1744048296.700 [Default:CheckIn:E] Stopped
2025-04-07T17:51:36.700Z,1744048296.700 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:51:36.700Z,1744048296.700 [Default:CheckIn] Stopped
2025-04-07T17:51:36.701Z,1744048296.701 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:51:36.701Z,1744048296.701 [Default:CheckIn](INFO): Running loop #17
2025-04-07T17:51:36.701Z,1744048296.701 [Default:CheckIn] Running Loop=17
2025-04-07T17:51:36.701Z,1744048296.701 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:51:36.701Z,1744048296.701 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:51:38.691Z,1744048298.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175137.00,A,3648.15413,N,12147.22421,W,0.019,136.77,070425,,,D*7A
2025-04-07T17:51:38.693Z,1744048298.693 [NAL9602](INFO): GPS fix at 20250407T175137: (36.802569, -121.787070)
2025-04-07T17:51:38.704Z,1744048298.704 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:51:38.704Z,1744048298.704 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:51:45.882Z,1744048305.882 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0052.lzma
2025-04-07T17:51:46.885Z,1744048306.885 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0052.lzma.bak
2025-04-07T17:51:46.885Z,1744048306.885 [DataOverHttps](INFO): SBD MOMSN=24562067
2025-04-07T17:51:52.025Z,1744048312.025 [NAL9602](INFO): SBD MO Status=0, MOMSN=62776, MT Status=0, MTMSN=0
2025-04-07T17:51:52.025Z,1744048312.025 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:52:03.026Z,1744048323.026 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20250407T161926/Express0053.lzma
2025-04-07T17:52:04.029Z,1744048324.029 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0053.lzma.bak
2025-04-07T17:52:04.029Z,1744048324.029 [DataOverHttps](INFO): SBD MOMSN=24562077
2025-04-07T17:52:05.371Z,1744048325.371 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:52:05.372Z,1744048325.372 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:52:05.372Z,1744048325.372 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:52:22.724Z,1744048342.724 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T17:57:05.957Z,1744048625.957 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T17:57:05.958Z,1744048625.958 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:57:05.958Z,1744048625.958 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:57:05.958Z,1744048625.958 [Default:CheckIn:D] Running Loop=1
2025-04-07T17:57:06.356Z,1744048626.356 [Default:CheckIn:D] Stopped
2025-04-07T17:57:06.356Z,1744048626.356 [Default:CheckIn:E] Running Loop=1
2025-04-07T17:57:06.770Z,1744048626.770 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.098633 min
2025-04-07T17:57:06.770Z,1744048626.770 [Default:CheckIn:E] Stopped
2025-04-07T17:57:06.770Z,1744048626.770 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T17:57:06.770Z,1744048626.770 [Default:CheckIn] Stopped
2025-04-07T17:57:06.771Z,1744048626.771 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:57:06.771Z,1744048626.771 [Default:CheckIn](INFO): Running loop #18
2025-04-07T17:57:06.771Z,1744048626.771 [Default:CheckIn] Running Loop=18
2025-04-07T17:57:06.771Z,1744048626.771 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:57:06.771Z,1744048626.771 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:57:08.774Z,1744048628.774 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175708.00,A,3648.15532,N,12147.22397,W,0.039,136.77,070425,,,D*7A
2025-04-07T17:57:08.776Z,1744048628.776 [NAL9602](INFO): GPS fix at 20250407T175708: (36.802589, -121.787066)
2025-04-07T17:57:08.787Z,1744048628.787 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:57:08.787Z,1744048628.787 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:57:16.543Z,1744048636.543 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0055.lzma
2025-04-07T17:57:17.545Z,1744048637.545 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0055.lzma.bak
2025-04-07T17:57:17.545Z,1744048637.545 [DataOverHttps](INFO): SBD MOMSN=24562143
2025-04-07T17:57:22.509Z,1744048642.509 [NAL9602](INFO): SBD MO Status=0, MOMSN=62777, MT Status=0, MTMSN=0
2025-04-07T17:57:22.509Z,1744048642.509 [NAL9602](INFO): No messages in MT queue
2025-04-07T17:57:33.486Z,1744048653.486 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0056.lzma
2025-04-07T17:57:34.490Z,1744048654.490 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0056.lzma.bak
2025-04-07T17:57:34.490Z,1744048654.490 [DataOverHttps](INFO): SBD MOMSN=24562148
2025-04-07T17:57:35.859Z,1744048655.859 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:57:35.859Z,1744048655.859 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:57:35.859Z,1744048655.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:57:53.216Z,1744048673.216 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:02:36.426Z,1744048956.426 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:02:36.427Z,1744048956.427 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:02:36.427Z,1744048956.427 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:02:36.427Z,1744048956.427 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:02:36.827Z,1744048956.827 [Default:CheckIn:D] Stopped
2025-04-07T18:02:36.827Z,1744048956.827 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:02:37.238Z,1744048957.238 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.606486 min
2025-04-07T18:02:37.238Z,1744048957.238 [Default:CheckIn:E] Stopped
2025-04-07T18:02:37.238Z,1744048957.238 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:02:37.238Z,1744048957.238 [Default:CheckIn] Stopped
2025-04-07T18:02:37.239Z,1744048957.239 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:02:37.239Z,1744048957.239 [Default:CheckIn](INFO): Running loop #19
2025-04-07T18:02:37.239Z,1744048957.239 [Default:CheckIn] Running Loop=19
2025-04-07T18:02:37.239Z,1744048957.239 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:02:37.239Z,1744048957.239 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:02:39.256Z,1744048959.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180238.00,A,3648.15424,N,12147.22433,W,0.039,136.77,070425,,,D*79
2025-04-07T18:02:39.258Z,1744048959.258 [NAL9602](INFO): GPS fix at 20250407T180238: (36.802571, -121.787072)
2025-04-07T18:02:39.269Z,1744048959.269 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:02:39.269Z,1744048959.269 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:02:47.030Z,1744048967.030 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0058.lzma
2025-04-07T18:02:48.033Z,1744048968.033 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0058.lzma.bak
2025-04-07T18:02:48.033Z,1744048968.033 [DataOverHttps](INFO): SBD MOMSN=24562274
2025-04-07T18:02:52.611Z,1744048972.611 [NAL9602](INFO): SBD MO Status=0, MOMSN=62778, MT Status=0, MTMSN=0
2025-04-07T18:02:52.611Z,1744048972.611 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:03:07.198Z,1744048987.198 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T161926/Express0059.lzma
2025-04-07T18:03:08.201Z,1744048988.201 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0059.lzma.bak
2025-04-07T18:03:08.201Z,1744048988.201 [DataOverHttps](INFO): SBD MOMSN=24562282
2025-04-07T18:03:09.601Z,1744048989.601 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:03:09.602Z,1744048989.602 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:03:09.602Z,1744048989.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:03:23.324Z,1744049003.324 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:08:10.223Z,1744049290.223 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:08:10.223Z,1744049290.223 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:08:10.223Z,1744049290.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:08:10.223Z,1744049290.223 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:08:10.615Z,1744049290.615 [Default:CheckIn:D] Stopped
2025-04-07T18:08:10.615Z,1744049290.615 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:08:11.018Z,1744049291.018 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.169621 min
2025-04-07T18:08:11.018Z,1744049291.018 [Default:CheckIn:E] Stopped
2025-04-07T18:08:11.018Z,1744049291.018 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:08:11.018Z,1744049291.018 [Default:CheckIn] Stopped
2025-04-07T18:08:11.019Z,1744049291.019 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:08:11.019Z,1744049291.019 [Default:CheckIn](INFO): Running loop #20
2025-04-07T18:08:11.019Z,1744049291.019 [Default:CheckIn] Running Loop=20
2025-04-07T18:08:11.019Z,1744049291.019 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:08:11.019Z,1744049291.019 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:08:13.027Z,1744049293.027 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180812.00,A,3648.15455,N,12147.22475,W,0.058,136.77,070425,,,D*78
2025-04-07T18:08:13.029Z,1744049293.029 [NAL9602](INFO): GPS fix at 20250407T180812: (36.802576, -121.787079)
2025-04-07T18:08:13.040Z,1744049293.040 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:08:13.040Z,1744049293.040 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:08:22.326Z,1744049302.326 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20250407T161926/Courier0061.lzma
2025-04-07T18:08:23.329Z,1744049303.329 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0061.lzma.bak
2025-04-07T18:08:23.329Z,1744049303.329 [DataOverHttps](INFO): SBD MOMSN=24562379
2025-04-07T18:08:25.568Z,1744049305.568 [NAL9602](INFO): SBD MO Status=0, MOMSN=62779, MT Status=0, MTMSN=0
2025-04-07T18:08:25.568Z,1744049305.568 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:08:41.211Z,1744049321.211 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20250407T161926/Express0062.lzma
2025-04-07T18:08:42.213Z,1744049322.213 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0062.lzma.bak
2025-04-07T18:08:42.213Z,1744049322.213 [DataOverHttps](INFO): SBD MOMSN=24562386
2025-04-07T18:08:43.366Z,1744049323.366 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:08:43.366Z,1744049323.366 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:08:43.366Z,1744049323.366 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:08:56.310Z,1744049336.310 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:13:43.818Z,1744049623.818 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:13:43.818Z,1744049623.818 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:13:43.818Z,1744049623.818 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:13:43.818Z,1744049623.818 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:13:44.230Z,1744049624.230 [Default:CheckIn:D] Stopped
2025-04-07T18:13:44.230Z,1744049624.230 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:13:44.636Z,1744049624.636 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.729867 min
2025-04-07T18:13:44.636Z,1744049624.636 [Default:CheckIn:E] Stopped
2025-04-07T18:13:44.636Z,1744049624.636 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:13:44.637Z,1744049624.637 [Default:CheckIn] Stopped
2025-04-07T18:13:44.637Z,1744049624.637 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:13:44.637Z,1744049624.637 [Default:CheckIn](INFO): Running loop #21
2025-04-07T18:13:44.637Z,1744049624.637 [Default:CheckIn] Running Loop=21
2025-04-07T18:13:44.637Z,1744049624.637 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:13:44.637Z,1744049624.637 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:13:46.641Z,1744049626.641 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181345.00,A,3648.15442,N,12147.22063,W,0.136,0.00,070425,,,D*78
2025-04-07T18:13:46.644Z,1744049626.644 [NAL9602](INFO): GPS fix at 20250407T181345: (36.802574, -121.787010)
2025-04-07T18:13:46.683Z,1744049626.683 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:13:46.683Z,1744049626.683 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:13:54.270Z,1744049634.270 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0064.lzma
2025-04-07T18:13:55.273Z,1744049635.273 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0064.lzma.bak
2025-04-07T18:13:55.273Z,1744049635.273 [DataOverHttps](INFO): SBD MOMSN=24562423
2025-04-07T18:14:11.368Z,1744049651.368 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T161926/Express0065.lzma
2025-04-07T18:14:12.369Z,1744049652.369 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0065.lzma.bak
2025-04-07T18:14:12.369Z,1744049652.369 [DataOverHttps](INFO): SBD MOMSN=24562430
2025-04-07T18:14:13.718Z,1744049653.718 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:14:13.718Z,1744049653.718 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:14:13.718Z,1744049653.718 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:14:16.533Z,1744049656.533 [NAL9602](INFO): SBD MO Status=2, MOMSN=62780, MT Status=2, MTMSN=0
2025-04-07T18:14:16.533Z,1744049656.533 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T18:14:31.553Z,1744049671.553 [NAL9602](INFO): SBD MO Status=0, MOMSN=62780, MT Status=0, MTMSN=0
2025-04-07T18:14:31.553Z,1744049671.553 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:15:02.289Z,1744049702.289 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:19:14.214Z,1744049954.214 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:19:14.214Z,1744049954.214 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:19:14.214Z,1744049954.214 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:19:14.214Z,1744049954.214 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:19:14.626Z,1744049954.626 [Default:CheckIn:D] Stopped
2025-04-07T18:19:14.626Z,1744049954.626 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.236466 min
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn:E] Stopped
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn] Stopped
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn](INFO): Running loop #22
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn] Running Loop=22
2025-04-07T18:19:15.040Z,1744049955.040 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:19:15.041Z,1744049955.041 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:19:17.032Z,1744049957.032 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181916.00,A,3648.15262,N,12147.22316,W,0.019,0.00,070425,,,D*7D
2025-04-07T18:19:17.034Z,1744049957.034 [NAL9602](INFO): GPS fix at 20250407T181916: (36.802544, -121.787053)
2025-04-07T18:19:17.045Z,1744049957.045 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:19:17.045Z,1744049957.045 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:19:25.130Z,1744049965.130 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0067.lzma
2025-04-07T18:19:26.133Z,1744049966.133 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0067.lzma.bak
2025-04-07T18:19:26.133Z,1744049966.133 [DataOverHttps](INFO): SBD MOMSN=24562525
2025-04-07T18:19:32.389Z,1744049972.389 [NAL9602](INFO): SBD MO Status=0, MOMSN=62781, MT Status=0, MTMSN=0
2025-04-07T18:19:32.389Z,1744049972.389 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:19:42.174Z,1744049982.174 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T161926/Express0068.lzma
2025-04-07T18:19:43.177Z,1744049983.177 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0068.lzma.bak
2025-04-07T18:19:43.177Z,1744049983.177 [DataOverHttps](INFO): SBD MOMSN=24562534
2025-04-07T18:19:44.519Z,1744049984.519 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:19:44.520Z,1744049984.520 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:19:44.520Z,1744049984.520 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:20:03.088Z,1744050003.088 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:24:45.332Z,1744050285.332 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:24:45.333Z,1744050285.333 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:24:45.333Z,1744050285.333 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:24:45.333Z,1744050285.333 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:24:45.745Z,1744050285.745 [Default:CheckIn:D] Stopped
2025-04-07T18:24:45.745Z,1744050285.745 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:24:46.142Z,1744050286.142 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.755127 min
2025-04-07T18:24:46.142Z,1744050286.142 [Default:CheckIn:E] Stopped
2025-04-07T18:24:46.142Z,1744050286.142 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:24:46.142Z,1744050286.142 [Default:CheckIn] Stopped
2025-04-07T18:24:46.142Z,1744050286.142 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:24:46.143Z,1744050286.143 [Default:CheckIn](INFO): Running loop #23
2025-04-07T18:24:46.143Z,1744050286.143 [Default:CheckIn] Running Loop=23
2025-04-07T18:24:46.143Z,1744050286.143 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:24:46.143Z,1744050286.143 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:24:48.154Z,1744050288.154 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182447.00,A,3648.15253,N,12147.22611,W,0.039,0.00,070425,,,D*75
2025-04-07T18:24:48.156Z,1744050288.156 [NAL9602](INFO): GPS fix at 20250407T182447: (36.802542, -121.787102)
2025-04-07T18:24:48.176Z,1744050288.176 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:24:48.176Z,1744050288.176 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:24:58.122Z,1744050298.122 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0070.lzma
2025-04-07T18:24:59.125Z,1744050299.125 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0070.lzma.bak
2025-04-07T18:24:59.125Z,1744050299.125 [DataOverHttps](INFO): SBD MOMSN=24562559
2025-04-07T18:25:02.833Z,1744050302.833 [NAL9602](INFO): SBD MO Status=0, MOMSN=62782, MT Status=0, MTMSN=0
2025-04-07T18:25:02.833Z,1744050302.833 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:25:15.096Z,1744050315.096 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0071.lzma
2025-04-07T18:25:16.097Z,1744050316.097 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0071.lzma.bak
2025-04-07T18:25:16.097Z,1744050316.097 [DataOverHttps](INFO): SBD MOMSN=24562599
2025-04-07T18:25:17.398Z,1744050317.398 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:25:17.398Z,1744050317.398 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:25:17.398Z,1744050317.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:25:33.539Z,1744050333.539 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:30:18.186Z,1744050618.186 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:30:18.186Z,1744050618.186 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:30:18.186Z,1744050618.186 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:30:18.186Z,1744050618.186 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:30:18.582Z,1744050618.582 [Default:CheckIn:D] Stopped
2025-04-07T18:30:18.583Z,1744050618.583 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:30:19.046Z,1744050619.046 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.302409 min
2025-04-07T18:30:19.046Z,1744050619.046 [Default:CheckIn:E] Stopped
2025-04-07T18:30:19.046Z,1744050619.046 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:30:19.046Z,1744050619.046 [Default:CheckIn] Stopped
2025-04-07T18:30:19.046Z,1744050619.046 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:30:19.046Z,1744050619.046 [Default:CheckIn](INFO): Running loop #24
2025-04-07T18:30:19.046Z,1744050619.046 [Default:CheckIn] Running Loop=24
2025-04-07T18:30:19.055Z,1744050619.055 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:30:19.055Z,1744050619.055 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:30:20.998Z,1744050620.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183020.00,A,3648.15197,N,12147.22581,W,0.039,0.00,070425,,,D*70
2025-04-07T18:30:21.000Z,1744050621.000 [NAL9602](INFO): GPS fix at 20250407T183020: (36.802533, -121.787097)
2025-04-07T18:30:21.060Z,1744050621.060 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:30:21.060Z,1744050621.060 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:30:30.166Z,1744050630.166 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0073.lzma
2025-04-07T18:30:31.169Z,1744050631.169 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0073.lzma.bak
2025-04-07T18:30:31.169Z,1744050631.169 [DataOverHttps](INFO): SBD MOMSN=24562989
2025-04-07T18:30:38.381Z,1744050638.381 [NAL9602](INFO): SBD MO Status=0, MOMSN=62783, MT Status=0, MTMSN=0
2025-04-07T18:30:38.381Z,1744050638.381 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:30:47.019Z,1744050647.019 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T161926/Express0074.lzma
2025-04-07T18:30:48.021Z,1744050648.021 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0074.lzma.bak
2025-04-07T18:30:48.021Z,1744050648.021 [DataOverHttps](INFO): SBD MOMSN=24562997
2025-04-07T18:30:49.363Z,1744050649.363 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:30:49.363Z,1744050649.363 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:30:49.363Z,1744050649.363 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:31:09.128Z,1744050669.128 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:35:50.001Z,1744050950.001 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:35:50.001Z,1744050950.001 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:35:50.001Z,1744050950.001 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:35:50.001Z,1744050950.001 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:35:50.386Z,1744050950.386 [Default:CheckIn:D] Stopped
2025-04-07T18:35:50.386Z,1744050950.386 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.832463 min
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn:E] Stopped
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn] Stopped
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn](INFO): Running loop #25
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn] Running Loop=25
2025-04-07T18:35:50.789Z,1744050950.789 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:35:50.790Z,1744050950.790 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:35:52.811Z,1744050952.811 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183552.00,A,3648.14717,N,12147.22212,W,0.058,0.00,070425,,,D*75
2025-04-07T18:35:52.813Z,1744050952.813 [NAL9602](INFO): GPS fix at 20250407T183552: (36.802453, -121.787035)
2025-04-07T18:35:52.824Z,1744050952.824 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:35:52.824Z,1744050952.824 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:36:00.370Z,1744050960.370 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0076.lzma
2025-04-07T18:36:01.373Z,1744050961.373 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0076.lzma.bak
2025-04-07T18:36:01.373Z,1744050961.373 [DataOverHttps](INFO): SBD MOMSN=24563113
2025-04-07T18:36:16.633Z,1744050976.633 [NAL9602](INFO): SBD MO Status=0, MOMSN=62784, MT Status=0, MTMSN=0
2025-04-07T18:36:16.634Z,1744050976.634 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:36:17.438Z,1744050977.438 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0077.lzma
2025-04-07T18:36:18.441Z,1744050978.441 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0077.lzma.bak
2025-04-07T18:36:18.441Z,1744050978.441 [DataOverHttps](INFO): SBD MOMSN=24563155
2025-04-07T18:36:19.510Z,1744050979.510 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:36:19.510Z,1744050979.510 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:36:19.510Z,1744050979.510 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:36:31.658Z,1744050991.658 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:36:43.375Z,1744051003.375 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:36:47.432Z,1744051007.432 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:36:55.540Z,1744051015.540 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:37:07.683Z,1744051027.683 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:37:18.990Z,1744051038.990 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:37:30.706Z,1744051050.706 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:37:42.826Z,1744051062.826 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:37:54.954Z,1744051074.954 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:40:21.203Z,1744051221.203 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:40:34.130Z,1744051234.130 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:40:47.462Z,1744051247.462 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:41:00.799Z,1744051260.799 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:41:14.539Z,1744051274.539 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:41:20.231Z,1744051280.231 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:41:20.231Z,1744051280.231 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:41:20.231Z,1744051280.231 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:41:20.231Z,1744051280.231 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:41:20.615Z,1744051280.615 [Default:CheckIn:D] Stopped
2025-04-07T18:41:20.615Z,1744051280.615 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:41:21.018Z,1744051281.018 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.336296 min
2025-04-07T18:41:21.018Z,1744051281.018 [Default:CheckIn:E] Stopped
2025-04-07T18:41:21.019Z,1744051281.019 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:41:21.019Z,1744051281.019 [Default:CheckIn] Stopped
2025-04-07T18:41:21.019Z,1744051281.019 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:41:21.019Z,1744051281.019 [Default:CheckIn](INFO): Running loop #26
2025-04-07T18:41:21.019Z,1744051281.019 [Default:CheckIn] Running Loop=26
2025-04-07T18:41:21.019Z,1744051281.019 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:41:21.019Z,1744051281.019 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:41:23.022Z,1744051283.022 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184122.00,A,3648.15345,N,12147.22511,W,0.019,0.00,070425,,,D*72
2025-04-07T18:41:23.024Z,1744051283.024 [NAL9602](INFO): GPS fix at 20250407T184122: (36.802557, -121.787085)
2025-04-07T18:41:23.060Z,1744051283.060 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:41:23.060Z,1744051283.060 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:41:27.867Z,1744051287.867 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:41:30.610Z,1744051290.610 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0079.lzma
2025-04-07T18:41:31.613Z,1744051291.613 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0079.lzma.bak
2025-04-07T18:41:31.613Z,1744051291.613 [DataOverHttps](INFO): SBD MOMSN=24563344
2025-04-07T18:41:41.199Z,1744051301.199 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:41:47.802Z,1744051307.802 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0080.lzma
2025-04-07T18:41:48.805Z,1744051308.805 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0080.lzma.bak
2025-04-07T18:41:48.805Z,1744051308.805 [DataOverHttps](INFO): SBD MOMSN=24563350
2025-04-07T18:41:50.109Z,1744051310.109 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:41:50.109Z,1744051310.109 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:41:50.109Z,1744051310.109 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:41:53.729Z,1744051313.729 [NAL9602](INFO): SBD MO Status=2, MOMSN=62785, MT Status=2, MTMSN=0
2025-04-07T18:41:53.729Z,1744051313.729 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T18:41:54.531Z,1744051314.531 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:42:08.269Z,1744051328.269 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:42:10.758Z,1744051330.758 [NAL9602](INFO): SBD MO Status=0, MOMSN=62785, MT Status=0, MTMSN=0
2025-04-07T18:42:10.758Z,1744051330.758 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:42:22.003Z,1744051342.003 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:42:36.168Z,1744051356.168 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2025-04-07T18:42:41.433Z,1744051361.433 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:42:49.102Z,1744051369.102 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5.
2025-04-07T18:42:49.113Z,1744051369.113 [BPC1](INFO): Received data from all battery sticks.
2025-04-07T18:46:50.752Z,1744051610.752 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:46:50.752Z,1744051610.752 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:46:50.752Z,1744051610.752 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:46:50.753Z,1744051610.753 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:46:51.168Z,1744051611.168 [Default:CheckIn:D] Stopped
2025-04-07T18:46:51.168Z,1744051611.168 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.845492 min
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn:E] Stopped
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn] Stopped
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn](INFO): Running loop #27
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn] Running Loop=27
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:46:51.544Z,1744051611.544 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:46:53.545Z,1744051613.545 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184652.00,A,3648.15303,N,12147.22333,W,0.097,0.00,070425,,,D*70
2025-04-07T18:46:53.548Z,1744051613.548 [NAL9602](INFO): GPS fix at 20250407T184652: (36.802551, -121.787055)
2025-04-07T18:46:53.584Z,1744051613.584 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:46:53.584Z,1744051613.584 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:47:01.610Z,1744051621.610 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250407T161926/Courier0082.lzma
2025-04-07T18:47:02.613Z,1744051622.613 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0082.lzma.bak
2025-04-07T18:47:02.613Z,1744051622.613 [DataOverHttps](INFO): SBD MOMSN=24563383
2025-04-07T18:47:05.269Z,1744051625.269 [NAL9602](INFO): SBD MO Status=0, MOMSN=62786, MT Status=0, MTMSN=0
2025-04-07T18:47:05.269Z,1744051625.269 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:47:18.658Z,1744051638.658 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250407T161926/Express0083.lzma
2025-04-07T18:47:19.661Z,1744051639.661 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0083.lzma.bak
2025-04-07T18:47:19.661Z,1744051639.661 [DataOverHttps](INFO): SBD MOMSN=24563425
2025-04-07T18:47:21.051Z,1744051641.051 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:47:21.051Z,1744051641.051 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:47:21.051Z,1744051641.051 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:47:35.969Z,1744051655.969 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:52:21.707Z,1744051941.707 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:52:21.707Z,1744051941.707 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:52:21.707Z,1744051941.707 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:52:21.708Z,1744051941.708 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:52:22.112Z,1744051942.112 [Default:CheckIn:D] Stopped
2025-04-07T18:52:22.112Z,1744051942.112 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:52:22.519Z,1744051942.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.361230 min
2025-04-07T18:52:22.519Z,1744051942.519 [Default:CheckIn:E] Stopped
2025-04-07T18:52:22.519Z,1744051942.519 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:52:22.520Z,1744051942.520 [Default:CheckIn] Stopped
2025-04-07T18:52:22.520Z,1744051942.520 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:52:22.520Z,1744051942.520 [Default:CheckIn](INFO): Running loop #28
2025-04-07T18:52:22.520Z,1744051942.520 [Default:CheckIn] Running Loop=28
2025-04-07T18:52:22.520Z,1744051942.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:52:22.520Z,1744051942.520 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:52:24.517Z,1744051944.517 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185223.00,A,3648.15024,N,12147.22569,W,1.516,145.71,070425,,,D*77
2025-04-07T18:52:24.520Z,1744051944.520 [NAL9602](INFO): GPS fix at 20250407T185223: (36.802504, -121.787095)
2025-04-07T18:52:24.575Z,1744051944.575 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:52:24.575Z,1744051944.575 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:52:32.134Z,1744051952.134 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0085.lzma
2025-04-07T18:52:33.137Z,1744051953.137 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0085.lzma.bak
2025-04-07T18:52:33.137Z,1744051953.137 [DataOverHttps](INFO): SBD MOMSN=24563466
2025-04-07T18:52:47.561Z,1744051967.561 [NAL9602](INFO): SBD MO Status=2, MOMSN=62787, MT Status=2, MTMSN=0
2025-04-07T18:52:47.561Z,1744051967.561 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T18:52:50.767Z,1744051970.767 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T161926/Express0086.lzma
2025-04-07T18:52:51.765Z,1744051971.765 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0086.lzma.bak
2025-04-07T18:52:51.765Z,1744051971.765 [DataOverHttps](INFO): SBD MOMSN=24563472
2025-04-07T18:52:52.860Z,1744051972.860 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:52:52.860Z,1744051972.860 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:52:52.860Z,1744051972.860 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:52:58.505Z,1744051978.505 [NAL9602](INFO): SBD MO Status=0, MOMSN=62787, MT Status=0, MTMSN=0
2025-04-07T18:52:58.505Z,1744051978.505 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:53:29.190Z,1744052009.190 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:57:53.414Z,1744052273.414 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:57:53.414Z,1744052273.414 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:57:53.414Z,1744052273.414 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:57:53.414Z,1744052273.414 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:57:53.826Z,1744052273.826 [Default:CheckIn:D] Stopped
2025-04-07T18:57:53.826Z,1744052273.826 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:57:54.234Z,1744052274.234 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 155.889795 min
2025-04-07T18:57:54.234Z,1744052274.234 [Default:CheckIn:E] Stopped
2025-04-07T18:57:54.234Z,1744052274.234 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:57:54.234Z,1744052274.234 [Default:CheckIn] Stopped
2025-04-07T18:57:54.234Z,1744052274.234 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:57:54.234Z,1744052274.234 [Default:CheckIn](INFO): Running loop #29
2025-04-07T18:57:54.234Z,1744052274.234 [Default:CheckIn] Running Loop=29
2025-04-07T18:57:54.235Z,1744052274.235 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:57:54.235Z,1744052274.235 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:57:56.237Z,1744052276.237 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185755.00,A,3648.15328,N,12147.21826,W,0.136,106.96,070425,,,A*75
2025-04-07T18:57:56.240Z,1744052276.240 [NAL9602](INFO): GPS fix at 20250407T185755: (36.802555, -121.786971)
2025-04-07T18:57:56.275Z,1744052276.275 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:57:56.275Z,1744052276.275 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:58:03.914Z,1744052283.914 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0088.lzma
2025-04-07T18:58:04.917Z,1744052284.917 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0088.lzma.bak
2025-04-07T18:58:04.917Z,1744052284.917 [DataOverHttps](INFO): SBD MOMSN=24563558
2025-04-07T18:58:09.569Z,1744052289.569 [NAL9602](INFO): SBD MO Status=0, MOMSN=62788, MT Status=0, MTMSN=0
2025-04-07T18:58:09.569Z,1744052289.569 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:58:23.814Z,1744052303.814 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T161926/Express0089.lzma
2025-04-07T18:58:24.817Z,1744052304.817 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0089.lzma.bak
2025-04-07T18:58:24.817Z,1744052304.817 [DataOverHttps](INFO): SBD MOMSN=24563564
2025-04-07T18:58:26.207Z,1744052306.207 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:58:26.207Z,1744052306.207 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:58:26.207Z,1744052306.207 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:58:40.309Z,1744052320.309 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:03:26.771Z,1744052606.771 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:03:26.771Z,1744052606.771 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:03:26.771Z,1744052606.771 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:03:26.771Z,1744052606.771 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:03:27.170Z,1744052607.170 [Default:CheckIn:D] Stopped
2025-04-07T19:03:27.170Z,1744052607.170 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:03:27.571Z,1744052607.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 161.445524 min
2025-04-07T19:03:27.571Z,1744052607.571 [Default:CheckIn:E] Stopped
2025-04-07T19:03:27.571Z,1744052607.571 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:03:27.571Z,1744052607.571 [Default:CheckIn] Stopped
2025-04-07T19:03:27.571Z,1744052607.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:03:27.571Z,1744052607.571 [Default:CheckIn](INFO): Running loop #30
2025-04-07T19:03:27.571Z,1744052607.571 [Default:CheckIn] Running Loop=30
2025-04-07T19:03:27.572Z,1744052607.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:03:27.572Z,1744052607.572 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:03:29.579Z,1744052609.579 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190328.00,A,3648.15251,N,12147.21871,W,0.078,154.88,070425,,,A*71
2025-04-07T19:03:29.581Z,1744052609.581 [NAL9602](INFO): GPS fix at 20250407T190328: (36.802542, -121.786979)
2025-04-07T19:03:29.592Z,1744052609.592 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:03:29.592Z,1744052609.592 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:03:36.802Z,1744052616.802 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0091.lzma
2025-04-07T19:03:37.805Z,1744052617.805 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0091.lzma.bak
2025-04-07T19:03:37.805Z,1744052617.805 [DataOverHttps](INFO): SBD MOMSN=24563593
2025-04-07T19:03:53.825Z,1744052633.825 [NAL9602](INFO): SBD MO Status=0, MOMSN=62789, MT Status=0, MTMSN=0
2025-04-07T19:03:53.825Z,1744052633.825 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:03:54.239Z,1744052634.239 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T161926/Express0092.lzma
2025-04-07T19:03:55.241Z,1744052635.241 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0092.lzma.bak
2025-04-07T19:03:55.241Z,1744052635.241 [DataOverHttps](INFO): SBD MOMSN=24563605
2025-04-07T19:03:56.283Z,1744052636.283 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:03:56.283Z,1744052636.283 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:03:56.284Z,1744052636.284 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:04:24.520Z,1744052664.520 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:08:56.832Z,1744052936.832 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:08:56.832Z,1744052936.832 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:08:56.832Z,1744052936.832 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:08:56.832Z,1744052936.832 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:08:57.238Z,1744052937.238 [Default:CheckIn:D] Stopped
2025-04-07T19:08:57.238Z,1744052937.238 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:08:57.637Z,1744052937.637 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 166.946663 min
2025-04-07T19:08:57.637Z,1744052937.637 [Default:CheckIn:E] Stopped
2025-04-07T19:08:57.637Z,1744052937.637 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:08:57.637Z,1744052937.637 [Default:CheckIn] Stopped
2025-04-07T19:08:57.637Z,1744052937.637 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:08:57.638Z,1744052937.638 [Default:CheckIn](INFO): Running loop #31
2025-04-07T19:08:57.638Z,1744052937.638 [Default:CheckIn] Running Loop=31
2025-04-07T19:08:57.638Z,1744052937.638 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:08:57.638Z,1744052937.638 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:08:59.645Z,1744052939.645 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190858.00,A,3648.15226,N,12147.22058,W,0.389,154.88,070425,,,A*70
2025-04-07T19:08:59.648Z,1744052939.648 [NAL9602](INFO): GPS fix at 20250407T190858: (36.802538, -121.787010)
2025-04-07T19:08:59.687Z,1744052939.687 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:08:59.687Z,1744052939.687 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:09:06.746Z,1744052946.746 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0094.lzma
2025-04-07T19:09:07.749Z,1744052947.749 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0094.lzma.bak
2025-04-07T19:09:07.749Z,1744052947.749 [DataOverHttps](INFO): SBD MOMSN=24563689
2025-04-07T19:09:23.946Z,1744052963.946 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T161926/Express0095.lzma
2025-04-07T19:09:24.949Z,1744052964.949 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0095.lzma.bak
2025-04-07T19:09:24.949Z,1744052964.949 [DataOverHttps](INFO): SBD MOMSN=24563696
2025-04-07T19:09:26.345Z,1744052966.345 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:09:26.345Z,1744052966.345 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:09:26.345Z,1744052966.345 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:09:48.936Z,1744052988.936 [NAL9602](INFO): SBD MO Status=2, MOMSN=62790, MT Status=2, MTMSN=0
2025-04-07T19:09:48.936Z,1744052988.936 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T19:10:25.703Z,1744053025.703 [NAL9602](INFO): SBD MO Status=2, MOMSN=62790, MT Status=2, MTMSN=0
2025-04-07T19:10:25.703Z,1744053025.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T19:10:37.417Z,1744053037.417 [NAL9602](INFO): SBD MO Status=0, MOMSN=62790, MT Status=0, MTMSN=0
2025-04-07T19:10:37.417Z,1744053037.417 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:11:08.117Z,1744053068.117 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:14:26.928Z,1744053266.928 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:14:26.928Z,1744053266.928 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:14:26.928Z,1744053266.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:14:26.928Z,1744053266.928 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:14:27.343Z,1744053267.343 [Default:CheckIn:D] Stopped
2025-04-07T19:14:27.343Z,1744053267.343 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:14:27.742Z,1744053267.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 172.448421 min
2025-04-07T19:14:27.742Z,1744053267.742 [Default:CheckIn:E] Stopped
2025-04-07T19:14:27.742Z,1744053267.742 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:14:27.742Z,1744053267.742 [Default:CheckIn] Stopped
2025-04-07T19:14:27.742Z,1744053267.742 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:14:27.759Z,1744053267.759 [Default:CheckIn](INFO): Running loop #32
2025-04-07T19:14:27.759Z,1744053267.759 [Default:CheckIn] Running Loop=32
2025-04-07T19:14:27.759Z,1744053267.759 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:14:27.759Z,1744053267.759 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:14:29.746Z,1744053269.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191429.00,A,3648.47759,N,12147.11309,W,5.676,357.59,070425,,,D*7E
2025-04-07T19:14:29.748Z,1744053269.748 [NAL9602](INFO): GPS fix at 20250407T191429: (36.807960, -121.785218)
2025-04-07T19:14:29.763Z,1744053269.763 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:14:29.763Z,1744053269.763 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:14:36.906Z,1744053276.906 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0097.lzma
2025-04-07T19:14:37.909Z,1744053277.909 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0097.lzma.bak
2025-04-07T19:14:37.909Z,1744053277.909 [DataOverHttps](INFO): SBD MOMSN=24563735
2025-04-07T19:14:42.686Z,1744053282.686 [NAL9602](INFO): SBD MO Status=0, MOMSN=62791, MT Status=0, MTMSN=0
2025-04-07T19:14:42.686Z,1744053282.686 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:14:56.855Z,1744053296.855 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250407T161926/Express0098.lzma
2025-04-07T19:14:57.857Z,1744053297.857 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0098.lzma.bak
2025-04-07T19:14:57.857Z,1744053297.857 [DataOverHttps](INFO): SBD MOMSN=24563741
2025-04-07T19:14:58.949Z,1744053298.949 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:14:58.949Z,1744053298.949 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:14:58.949Z,1744053298.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:15:13.442Z,1744053313.442 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:19:59.493Z,1744053599.493 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:19:59.493Z,1744053599.493 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:19:59.493Z,1744053599.493 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:19:59.494Z,1744053599.494 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:19:59.908Z,1744053599.908 [Default:CheckIn:D] Stopped
2025-04-07T19:19:59.908Z,1744053599.908 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:20:00.302Z,1744053600.302 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 177.991162 min
2025-04-07T19:20:00.302Z,1744053600.302 [Default:CheckIn:E] Stopped
2025-04-07T19:20:00.303Z,1744053600.303 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:20:00.303Z,1744053600.303 [Default:CheckIn] Stopped
2025-04-07T19:20:00.303Z,1744053600.303 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:20:00.303Z,1744053600.303 [Default:CheckIn](INFO): Running loop #33
2025-04-07T19:20:00.303Z,1744053600.303 [Default:CheckIn] Running Loop=33
2025-04-07T19:20:00.303Z,1744053600.303 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:20:00.303Z,1744053600.303 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:20:02.311Z,1744053602.311 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192001.00,A,3648.17664,N,12148.13552,W,27.175,259.07,070425,,,D*4C
2025-04-07T19:20:02.313Z,1744053602.313 [NAL9602](INFO): GPS fix at 20250407T192001: (36.802944, -121.802259)
2025-04-07T19:20:02.324Z,1744053602.324 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:20:02.324Z,1744053602.324 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:20:09.758Z,1744053609.758 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0100.lzma
2025-04-07T19:20:10.761Z,1744053610.761 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0100.lzma.bak
2025-04-07T19:20:10.761Z,1744053610.761 [DataOverHttps](INFO): SBD MOMSN=24563823
2025-04-07T19:20:29.519Z,1744053629.519 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20250407T161926/Express0101.lzma
2025-04-07T19:20:30.522Z,1744053630.522 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0101.lzma.bak
2025-04-07T19:20:30.522Z,1744053630.522 [DataOverHttps](INFO): SBD MOMSN=24563830
2025-04-07T19:20:31.858Z,1744053631.858 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:20:31.858Z,1744053631.858 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:20:31.858Z,1744053631.858 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:20:36.697Z,1744053636.697 [NAL9602](INFO): SBD MO Status=0, MOMSN=62792, MT Status=0, MTMSN=0
2025-04-07T19:20:36.697Z,1744053636.697 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:21:07.417Z,1744053667.417 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:24:35.996Z,1744053875.996 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:25:32.520Z,1744053932.520 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:25:32.520Z,1744053932.520 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:25:32.520Z,1744053932.520 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:25:32.520Z,1744053932.520 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:25:32.910Z,1744053932.910 [Default:CheckIn:D] Stopped
2025-04-07T19:25:32.910Z,1744053932.910 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:25:33.314Z,1744053933.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 183.541195 min
2025-04-07T19:25:33.314Z,1744053933.314 [Default:CheckIn:E] Stopped
2025-04-07T19:25:33.315Z,1744053933.315 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:25:33.315Z,1744053933.315 [Default:CheckIn] Stopped
2025-04-07T19:25:33.315Z,1744053933.315 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:25:33.315Z,1744053933.315 [Default:CheckIn](INFO): Running loop #34
2025-04-07T19:25:33.315Z,1744053933.315 [Default:CheckIn] Running Loop=34
2025-04-07T19:25:33.315Z,1744053933.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:25:33.315Z,1744053933.315 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:25:35.322Z,1744053935.322 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192534.00,A,3647.46158,N,12151.16658,W,18.175,262.39,070425,,,D*41
2025-04-07T19:25:35.333Z,1744053935.333 [NAL9602](INFO): GPS fix at 20250407T192534: (36.791026, -121.852776)
2025-04-07T19:25:35.345Z,1744053935.345 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:25:35.345Z,1744053935.345 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:25:43.602Z,1744053943.602 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0103.lzma
2025-04-07T19:25:44.605Z,1744053944.605 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0103.lzma.bak
2025-04-07T19:25:44.605Z,1744053944.605 [DataOverHttps](INFO): SBD MOMSN=24563871
2025-04-07T19:25:53.098Z,1744053953.098 [NAL9602](INFO): SBD MO Status=0, MOMSN=62793, MT Status=0, MTMSN=0
2025-04-07T19:25:53.098Z,1744053953.098 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:26:03.751Z,1744053963.751 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20250407T161926/Express0104.lzma
2025-04-07T19:26:04.753Z,1744053964.753 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0104.lzma.bak
2025-04-07T19:26:04.753Z,1744053964.753 [DataOverHttps](INFO): SBD MOMSN=24563879
2025-04-07T19:26:06.053Z,1744053966.053 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:26:06.053Z,1744053966.053 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:26:06.053Z,1744053966.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:26:23.797Z,1744053983.797 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:31:06.620Z,1744054266.620 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:31:06.620Z,1744054266.620 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:31:06.620Z,1744054266.620 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:31:06.620Z,1744054266.620 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:31:07.040Z,1744054267.040 [Default:CheckIn:D] Stopped
2025-04-07T19:31:07.040Z,1744054267.040 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 189.110042 min
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn:E] Stopped
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn] Stopped
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn](INFO): Running loop #35
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn] Running Loop=35
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:31:07.456Z,1744054267.456 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:31:09.433Z,1744054269.433 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193108.00,A,3647.81964,N,12152.70416,W,0.272,93.08,070425,,,A*4A
2025-04-07T19:31:09.435Z,1744054269.435 [NAL9602](INFO): GPS fix at 20250407T193108: (36.796994, -121.878403)
2025-04-07T19:31:09.446Z,1744054269.446 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:31:09.446Z,1744054269.446 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:31:21.550Z,1744054281.550 [NAL9602](INFO): SBD MO Status=0, MOMSN=62794, MT Status=0, MTMSN=0
2025-04-07T19:31:21.550Z,1744054281.550 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:31:36.346Z,1744054296.346 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0106.lzma
2025-04-07T19:31:45.210Z,1744054305.210 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250407T161926/Courier0106.lzma
2025-04-07T19:31:46.213Z,1744054306.213 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0106.lzma.bak
2025-04-07T19:31:46.213Z,1744054306.213 [DataOverHttps](INFO): SBD MOMSN=24563953
2025-04-07T19:31:52.256Z,1744054312.256 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:32:06.383Z,1744054326.383 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250407T161926/Express0107.lzma
2025-04-07T19:32:07.385Z,1744054327.385 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0107.lzma.bak
2025-04-07T19:32:07.385Z,1744054327.385 [DataOverHttps](INFO): SBD MOMSN=24563956
2025-04-07T19:32:08.842Z,1744054328.842 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:32:08.842Z,1744054328.842 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:32:08.842Z,1744054328.842 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:33:40.863Z,1744054420.863 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:34:11.987Z,1744054451.987 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:34:43.112Z,1744054483.112 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:35:14.243Z,1744054514.243 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:35:32.315Z,1744054532.315 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.319427
2025-04-07T19:36:15.495Z,1744054575.495 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:36:32.927Z,1744054592.927 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002959
2025-04-07T19:37:09.531Z,1744054629.531 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:37:09.531Z,1744054629.531 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:37:09.531Z,1744054629.531 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:37:09.531Z,1744054629.531 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:37:09.944Z,1744054629.944 [Default:CheckIn:D] Stopped
2025-04-07T19:37:09.944Z,1744054629.944 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:37:10.346Z,1744054630.346 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 195.158447 min
2025-04-07T19:37:10.351Z,1744054630.351 [Default:CheckIn:E] Stopped
2025-04-07T19:37:10.351Z,1744054630.351 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:37:10.351Z,1744054630.351 [Default:CheckIn] Stopped
2025-04-07T19:37:10.351Z,1744054630.351 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:37:10.352Z,1744054630.352 [Default:CheckIn](INFO): Running loop #36
2025-04-07T19:37:10.352Z,1744054630.352 [Default:CheckIn] Running Loop=36
2025-04-07T19:37:10.352Z,1744054630.352 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:37:10.352Z,1744054630.352 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:37:12.345Z,1744054632.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193711.00,A,3647.81991,N,12150.72957,W,0.505,78.51,070425,,,D*4D
2025-04-07T19:37:12.347Z,1744054632.347 [NAL9602](INFO): GPS fix at 20250407T193711: (36.796999, -121.845493)
2025-04-07T19:37:12.358Z,1744054632.358 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:37:12.358Z,1744054632.358 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:37:23.058Z,1744054643.058 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T161926/Courier0109.lzma
2025-04-07T19:37:24.061Z,1744054644.061 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Courier0109.lzma.bak
2025-04-07T19:37:24.061Z,1744054644.061 [DataOverHttps](INFO): SBD MOMSN=24563986
2025-04-07T19:37:40.263Z,1744054660.263 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20250407T161926/Express0110.lzma
2025-04-07T19:37:41.265Z,1744054661.265 [DataOverHttps](INFO): Moved sent file to Logs/20250407T161926/Express0110.lzma.bak
2025-04-07T19:37:41.265Z,1744054661.265 [DataOverHttps](INFO): SBD MOMSN=24563989
2025-04-07T19:37:42.659Z,1744054662.659 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:37:42.659Z,1744054662.659 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:37:42.659Z,1744054662.659 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:37:46.689Z,1744054666.689 [NAL9602](INFO): SBD MO Status=0, MOMSN=62795, MT Status=0, MTMSN=0
2025-04-07T19:37:46.689Z,1744054666.689 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:38:17.392Z,1744054697.392 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:41:23.596Z,1744054883.596 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T194122
2025-04-07T19:41:31.066Z,1744054891.066 [DataOverHttps](INFO): Received command: restart logs