2025-03-18T16:11:56.895Z,1742314316.895 [Supervisor](DEBUG): Initializing supervisor.
2025-03-18T16:11:56.914Z,1742314316.914 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-03-18T16:11:56.914Z,1742314316.914 [SyncHandler](INFO): Protected caller Thread ID is 9224
2025-03-18T16:11:56.915Z,1742314316.915 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-03-18T16:11:56.920Z,1742314316.920 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-03-18T16:11:56.922Z,1742314316.922 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9225
2025-03-18T16:11:56.948Z,1742314316.948 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-03-18T16:11:56.973Z,1742314316.973 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-03-18T16:11:56.974Z,1742314316.974 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-03-18T16:11:56.975Z,1742314316.975 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 9226
2025-03-18T16:11:56.979Z,1742314316.979 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-03-18T16:11:56.980Z,1742314316.980 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-03-18T16:11:56.980Z,1742314316.980 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9227
2025-03-18T16:11:56.982Z,1742314316.982 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-03-18T16:11:56.983Z,1742314316.983 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-03-18T16:11:56.984Z,1742314316.984 [logger ThreadHandler](INFO): Protected caller Thread ID is 9228
2025-03-18T16:11:56.988Z,1742314316.988 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-03-18T16:11:56.988Z,1742314316.988 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-03-18T16:11:56.991Z,1742314316.991 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-03-18T16:11:57.403Z,1742314317.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-03-18T16:11:57.404Z,1742314317.404 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-03-18T16:11:57.497Z,1742314317.497 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-03-18T16:11:57.617Z,1742314317.617 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-03-18T16:11:57.618Z,1742314317.618 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-03-18T16:11:57.759Z,1742314317.759 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-03-18T16:11:57.760Z,1742314317.760 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-03-18T16:11:58.118Z,1742314318.118 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-03-18T16:11:58.119Z,1742314318.119 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-03-18T16:11:58.228Z,1742314318.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-03-18T16:11:58.229Z,1742314318.229 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-03-18T16:11:58.657Z,1742314318.657 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-03-18T16:11:58.658Z,1742314318.658 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-03-18T16:11:58.898Z,1742314318.898 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-03-18T16:11:58.899Z,1742314318.899 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-03-18T16:11:58.991Z,1742314318.991 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-03-18T16:11:59.244Z,1742314319.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-03-18T16:11:59.244Z,1742314319.244 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-03-18T16:11:59.477Z,1742314319.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-03-18T16:11:59.477Z,1742314319.477 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-03-18T16:12:00.015Z,1742314320.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-03-18T16:12:00.015Z,1742314320.015 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-03-18T16:12:00.212Z,1742314320.212 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-03-18T16:12:00.213Z,1742314320.213 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-03-18T16:12:00.511Z,1742314320.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-03-18T16:12:00.512Z,1742314320.512 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-03-18T16:12:01.384Z,1742314321.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-03-18T16:12:01.385Z,1742314321.385 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-03-18T16:12:01.972Z,1742314321.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-03-18T16:12:01.974Z,1742314321.974 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/
2025-03-18T16:12:01.988Z,1742314321.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg
2025-03-18T16:12:02.101Z,1742314322.101 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg
2025-03-18T16:12:02.244Z,1742314322.244 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg
2025-03-18T16:12:02.339Z,1742314322.339 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg
2025-03-18T16:12:02.458Z,1742314322.458 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg
2025-03-18T16:12:02.557Z,1742314322.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg
2025-03-18T16:12:02.826Z,1742314322.826 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-03-18T16:12:02.826Z,1742314322.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg
2025-03-18T16:12:02.948Z,1742314322.948 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg
2025-03-18T16:12:03.058Z,1742314323.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg
2025-03-18T16:12:03.209Z,1742314323.209 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg
2025-03-18T16:12:03.308Z,1742314323.308 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/root/
2025-03-18T16:12:03.309Z,1742314323.309 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-03-18T16:12:03.336Z,1742314323.336 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-03-18T16:12:03.494Z,1742314323.494 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-03-18T16:12:03.495Z,1742314323.495 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-03-18T16:12:03.568Z,1742314323.568 [VerticalControl](DEBUG): Construct VerticalControl.
2025-03-18T16:12:03.629Z,1742314323.629 [VerticalControl] Loaded
2025-03-18T16:12:03.629Z,1742314323.629 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-03-18T16:12:03.632Z,1742314323.632 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-03-18T16:12:03.678Z,1742314323.678 [HorizontalControl] Loaded
2025-03-18T16:12:03.678Z,1742314323.678 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-03-18T16:12:03.681Z,1742314323.681 [SpeedControl](DEBUG): Construct SpeedControl.
2025-03-18T16:12:03.684Z,1742314323.684 [SpeedControl] Loaded
2025-03-18T16:12:03.684Z,1742314323.684 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-03-18T16:12:03.687Z,1742314323.687 [LoopControl](DEBUG): Construct LoopControl.
2025-03-18T16:12:03.687Z,1742314323.687 [LoopControl] Loaded
2025-03-18T16:12:03.687Z,1742314323.687 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-03-18T16:12:03.688Z,1742314323.688 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-03-18T16:12:03.688Z,1742314323.688 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-03-18T16:12:03.769Z,1742314323.769 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-03-18T16:12:03.770Z,1742314323.770 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-03-18T16:12:04.507Z,1742314324.507 [AHRS_M2] Loaded
2025-03-18T16:12:04.507Z,1742314324.507 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-03-18T16:12:04.809Z,1742314324.809 [BackseatComponent](INFO): Found secondary power supply at: /dev/loadC4
2025-03-18T16:12:04.810Z,1742314324.810 [BackseatComponent] Loaded
2025-03-18T16:12:04.810Z,1742314324.810 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-03-18T16:12:04.811Z,1742314324.811 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BA4E0
2025-03-18T16:12:04.812Z,1742314324.812 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9307
2025-03-18T16:12:04.817Z,1742314324.817 [LcmUniversalReporter] Loaded
2025-03-18T16:12:04.817Z,1742314324.817 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-03-18T16:12:05.623Z,1742314325.623 [BPC1] Loaded
2025-03-18T16:12:05.623Z,1742314325.623 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-03-18T16:12:05.727Z,1742314325.727 [DataOverHttps] Loaded
2025-03-18T16:12:05.727Z,1742314325.727 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-03-18T16:12:05.729Z,1742314325.729 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408EA4E0
2025-03-18T16:12:05.729Z,1742314325.729 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9308
2025-03-18T16:12:05.752Z,1742314325.752 [Depth_Keller] Loaded
2025-03-18T16:12:05.752Z,1742314325.752 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-03-18T16:12:05.757Z,1742314325.757 [DropWeight] Loaded
2025-03-18T16:12:05.757Z,1742314325.757 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-03-18T16:12:05.821Z,1742314325.821 [NAL9602] Loaded
2025-03-18T16:12:05.821Z,1742314325.821 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-03-18T16:12:05.851Z,1742314325.851 [Onboard] Loaded
2025-03-18T16:12:05.851Z,1742314325.851 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-03-18T16:12:05.852Z,1742314325.852 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4091A4E0
2025-03-18T16:12:05.853Z,1742314325.853 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9309
2025-03-18T16:12:05.866Z,1742314325.866 [Power24vConverter] Loaded
2025-03-18T16:12:05.867Z,1742314325.867 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-03-18T16:12:05.882Z,1742314325.882 [Radio_Surface] Loaded
2025-03-18T16:12:05.883Z,1742314325.883 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-03-18T16:12:05.884Z,1742314325.884 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4094A4E0
2025-03-18T16:12:05.884Z,1742314325.884 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9310
2025-03-18T16:12:05.899Z,1742314325.899 [Sonardyne_Nano] Loaded
2025-03-18T16:12:05.900Z,1742314325.900 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-03-18T16:12:05.924Z,1742314325.924 [Waterlinked] Loaded
2025-03-18T16:12:05.924Z,1742314325.924 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2025-03-18T16:12:05.925Z,1742314325.925 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-03-18T16:12:05.925Z,1742314325.925 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-03-18T16:12:05.941Z,1742314325.941 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-03-18T16:12:05.942Z,1742314325.942 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-03-18T16:12:05.990Z,1742314325.990 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-03-18T16:12:05.990Z,1742314325.990 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-03-18T16:12:06.188Z,1742314326.188 [SBIT](DEBUG): Construct Startup Built In Test.
2025-03-18T16:12:06.197Z,1742314326.197 [SBIT] Loaded
2025-03-18T16:12:06.197Z,1742314326.197 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-03-18T16:12:06.200Z,1742314326.200 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-03-18T16:12:06.213Z,1742314326.213 [IBIT] Loaded
2025-03-18T16:12:06.213Z,1742314326.213 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-03-18T16:12:06.218Z,1742314326.218 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-03-18T16:12:06.296Z,1742314326.296 [CBIT] Loaded
2025-03-18T16:12:06.297Z,1742314326.297 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-03-18T16:12:06.328Z,1742314326.328 [GFScanner] Loaded
2025-03-18T16:12:06.328Z,1742314326.328 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-03-18T16:12:06.328Z,1742314326.328 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-03-18T16:12:06.329Z,1742314326.329 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-03-18T16:12:06.737Z,1742314326.737 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-03-18T16:12:06.738Z,1742314326.738 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-03-18T16:12:06.809Z,1742314326.809 [DepthRateCalculator] Loaded
2025-03-18T16:12:06.809Z,1742314326.809 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-03-18T16:12:06.814Z,1742314326.814 [PitchRateCalculator] Loaded
2025-03-18T16:12:06.814Z,1742314326.814 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-03-18T16:12:06.824Z,1742314326.824 [SpeedCalculator] Loaded
2025-03-18T16:12:06.825Z,1742314326.825 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-03-18T16:12:06.829Z,1742314326.829 [YawRateCalculator] Loaded
2025-03-18T16:12:06.829Z,1742314326.829 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-03-18T16:12:06.848Z,1742314326.848 [ElevatorOffsetCalculator] Loaded
2025-03-18T16:12:06.848Z,1742314326.848 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-03-18T16:12:06.849Z,1742314326.849 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-03-18T16:12:06.849Z,1742314326.849 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-03-18T16:12:07.072Z,1742314327.072 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-03-18T16:12:07.072Z,1742314327.072 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-03-18T16:12:07.227Z,1742314327.227 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-03-18T16:12:07.227Z,1742314327.227 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-03-18T16:12:07.241Z,1742314327.241 [NavChart] Loaded
2025-03-18T16:12:07.241Z,1742314327.241 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-03-18T16:12:07.247Z,1742314327.247 [UniversalFixResidualReporter] Loaded
2025-03-18T16:12:07.247Z,1742314327.247 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-03-18T16:12:07.248Z,1742314327.248 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-03-18T16:12:07.248Z,1742314327.248 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-03-18T16:12:07.414Z,1742314327.414 [BuoyancyServo] Loaded
2025-03-18T16:12:07.415Z,1742314327.415 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-03-18T16:12:07.440Z,1742314327.440 [ElevatorServo] Loaded
2025-03-18T16:12:07.441Z,1742314327.441 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-03-18T16:12:07.462Z,1742314327.462 [MassServo] Loaded
2025-03-18T16:12:07.463Z,1742314327.463 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-03-18T16:12:07.483Z,1742314327.483 [RudderServo] Loaded
2025-03-18T16:12:07.483Z,1742314327.483 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-03-18T16:12:07.500Z,1742314327.500 [ThrusterHE] Loaded
2025-03-18T16:12:07.501Z,1742314327.501 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-03-18T16:12:07.501Z,1742314327.501 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-03-18T16:12:07.502Z,1742314327.502 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-03-18T16:12:07.721Z,1742314327.721 [CTD_Seabird] Loaded
2025-03-18T16:12:07.721Z,1742314327.721 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-03-18T16:12:07.722Z,1742314327.722 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BD54E0
2025-03-18T16:12:07.722Z,1742314327.722 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9311
2025-03-18T16:12:07.760Z,1742314327.760 [ESPComponent] Loaded
2025-03-18T16:12:07.760Z,1742314327.760 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-03-18T16:12:07.782Z,1742314327.782 [PAR_Licor] Loaded
2025-03-18T16:12:07.782Z,1742314327.782 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-03-18T16:12:07.783Z,1742314327.783 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-03-18T16:12:07.790Z,1742314327.790 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-03-18T16:12:07.797Z,1742314327.797 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-03-18T16:12:07.808Z,1742314327.808 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-03-18T16:12:07.809Z,1742314327.809 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C054E0
2025-03-18T16:12:07.809Z,1742314327.809 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9312
2025-03-18T16:12:07.813Z,1742314327.813 [Supervisor](INFO): Main Thread ID is 9222
2025-03-18T16:12:07.814Z,1742314327.814 [Supervisor](DEBUG): Running supervisor.
2025-03-18T16:12:07.814Z,1742314327.814 [CommandExec ThreadHandler](INFO): Handler Thread ID is 9313
2025-03-18T16:12:07.816Z,1742314327.816 [CommandExec](INFO): Initializing the command executive.
2025-03-18T16:12:07.818Z,1742314327.818 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9314
2025-03-18T16:12:07.820Z,1742314327.820 [controlThread ThreadHandler](INFO): Handler Thread ID is 9315
2025-03-18T16:12:07.821Z,1742314327.821 [controlThread](DEBUG): Initializing ControlThread
2025-03-18T16:12:07.822Z,1742314327.822 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-03-18T16:12:07.823Z,1742314327.823 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-03-18T16:12:07.824Z,1742314327.824 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-03-18T16:12:07.824Z,1742314327.824 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-03-18T16:12:07.830Z,1742314327.830 [SBIT](INFO): Initialize SBIT Component.
2025-03-18T16:12:07.831Z,1742314327.831 [SBIT](IMPORTANT): git: 2025-03-12_C
2025-03-18T16:12:07.831Z,1742314327.831 [SBIT](INFO): git hash: c930cdb2e5c1f1ff3673ee566a0d82f2333fbba8
2025-03-18T16:12:07.831Z,1742314327.831 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-03-18T16:12:07.832Z,1742314327.832 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #1 PREEMPT Tue Nov 28 15:04:22 PST 2023
2025-03-18T16:12:07.833Z,1742314327.833 [SBIT](INFO): Beginning SBIT in 82.000000 seconds.
2025-03-18T16:12:07.834Z,1742314327.834 [IBIT](INFO): Initialize IBIT Component.
2025-03-18T16:12:07.835Z,1742314327.835 [CBIT](DEBUG): Initialize CBIT Component.
2025-03-18T16:12:07.836Z,1742314327.836 [logger ThreadHandler](INFO): Handler Thread ID is 9316
2025-03-18T16:12:07.848Z,1742314327.848 [CBIT](DEBUG): Initialized mux pins.
2025-03-18T16:12:07.848Z,1742314327.848 [CBIT](DEBUG): Initializing the watchdog timer.
2025-03-18T16:12:07.857Z,1742314327.857 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9317
2025-03-18T16:12:07.869Z,1742314327.869 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9318
2025-03-18T16:12:07.870Z,1742314327.870 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-03-18T16:12:07.872Z,1742314327.872 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-03-18T16:12:07.873Z,1742314327.873 [CBIT](DEBUG): Initializing heartbeat.
2025-03-18T16:12:07.881Z,1742314327.881 [Onboard ThreadHandler](INFO): Handler Thread ID is 9319
2025-03-18T16:12:07.898Z,1742314327.898 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9320
2025-03-18T16:12:07.917Z,1742314327.917 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9321
2025-03-18T16:12:07.917Z,1742314327.917 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-03-18T16:12:07.922Z,1742314327.922 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9323
2025-03-18T16:12:07.928Z,1742314327.928 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-03-18T16:12:07.928Z,1742314327.928 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-03-18T16:12:07.929Z,1742314327.929 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-03-18T16:12:07.929Z,1742314327.929 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-03-18T16:12:07.929Z,1742314327.929 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-03-18T16:12:07.929Z,1742314327.929 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-03-18T16:12:07.929Z,1742314327.929 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-03-18T16:12:07.929Z,1742314327.929 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-03-18T16:12:07.944Z,1742314327.944 [CBIT](DEBUG): Deactivating emergency mode.
2025-03-18T16:12:07.984Z,1742314327.984 [CBIT](DEBUG): Backplane powered.
2025-03-18T16:12:07.984Z,1742314327.984 [GFScanner](DEBUG): Initializing GFScanner
2025-03-18T16:12:07.985Z,1742314327.985 [GFScanner](DEBUG): Deactivating GF circuits.
2025-03-18T16:12:07.989Z,1742314327.989 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-03-18T16:12:07.989Z,1742314327.989 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-03-18T16:12:07.990Z,1742314327.990 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-03-18T16:12:07.990Z,1742314327.990 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-03-18T16:12:07.990Z,1742314327.990 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-03-18T16:12:07.991Z,1742314327.991 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-03-18T16:12:07.992Z,1742314327.992 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-03-18T16:12:08.001Z,1742314328.001 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-03-18T16:12:08.002Z,1742314328.002 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-03-18T16:12:08.002Z,1742314328.002 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-03-18T16:12:08.006Z,1742314328.006 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-03-18T16:12:08.094Z,1742314328.094 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-03-18T16:12:08.099Z,1742314328.099 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-18T16:12:08.146Z,1742314328.146 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-03-18T16:12:08.147Z,1742314328.147 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-03-18T16:12:08.147Z,1742314328.147 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-03-18T16:12:08.158Z,1742314328.158 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-03-18T16:12:08.312Z,1742314328.312 [Radio_Surface](INFO): Powering up
2025-03-18T16:12:08.488Z,1742314328.488 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-03-18T16:12:08.515Z,1742314328.515 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-03-18T16:12:08.516Z,1742314328.516 [Default:A.Wait](DEBUG): Construct Wait.
2025-03-18T16:12:08.519Z,1742314328.519 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-18T16:12:08.549Z,1742314328.549 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-18T16:12:08.568Z,1742314328.568 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-18T16:12:08.574Z,1742314328.574 [Default:E.Execute](DEBUG): Construct Execute.
2025-03-18T16:12:08.590Z,1742314328.590 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-03-18T16:12:08.595Z,1742314328.595 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,Waterlinked,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-18T16:12:08.618Z,1742314328.618 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-03-18T16:12:08.690Z,1742314328.690 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.140412 decibar, -1.132002 m
2025-03-18T16:12:08.691Z,1742314328.691 [Power24vConverter](INFO): Powering up.
2025-03-18T16:12:08.692Z,1742314328.692 [Sonardyne_Nano](INFO): Initializing.
2025-03-18T16:12:08.719Z,1742314328.719 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-03-18T16:12:08.765Z,1742314328.765 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-03-18T16:12:08.772Z,1742314328.772 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-03-18T16:12:08.773Z,1742314328.773 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-03-18T16:12:08.780Z,1742314328.780 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-03-18T16:12:08.781Z,1742314328.781 [MassServo](DEBUG): Initializing EZServoServo.
2025-03-18T16:12:08.788Z,1742314328.788 [MassServo](DEBUG): Initializing MassServo.
2025-03-18T16:12:08.789Z,1742314328.789 [RudderServo](DEBUG): Initializing EZServoServo.
2025-03-18T16:12:08.796Z,1742314328.796 [RudderServo](DEBUG): Initializing RudderServo.
2025-03-18T16:12:08.798Z,1742314328.798 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-03-18T16:12:08.804Z,1742314328.804 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-03-18T16:12:08.807Z,1742314328.807 [CBIT](FAULT): Main Battery Failure
2025-03-18T16:12:09.050Z,1742314329.050 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-03-18T16:12:09.050Z,1742314329.050 [DropWeight] Hardware Fault, FailCount= 1
2025-03-18T16:12:09.050Z,1742314329.050 [DropWeight](ERROR): Hardware Fault
2025-03-18T16:12:09.083Z,1742314329.083 [CommandExec](FAULT): Scheduling is paused
2025-03-18T16:12:09.083Z,1742314329.083 [CBIT](INFO): Critical error at 20250318T161209
2025-03-18T16:12:09.084Z,1742314329.084 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-03-18T16:12:09.094Z,1742314329.094 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-03-18T16:12:09.095Z,1742314329.095 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-03-18T16:12:09.429Z,1742314329.429 [CBIT](INFO): Critical error at 20250318T161209
2025-03-18T16:12:10.623Z,1742314330.623 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-03-18T16:12:11.908Z,1742314331.908 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311
2025-03-18T16:12:12.268Z,1742314332.268 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging
2025-03-18T16:12:20.781Z,1742314340.781 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.039475
2025-03-18T16:12:36.152Z,1742314356.152 [NAL9602](INFO): Powering up NAL9602
2025-03-18T16:12:45.724Z,1742314365.724 [Waterlinked](INFO): Powering down
2025-03-18T16:12:47.214Z,1742314367.214 [NAL9602](INFO): NAL9602 initialized
2025-03-18T16:13:24.917Z,1742314404.917 [CommandExec](IMPORTANT): got command strobe off
2025-03-18T16:13:24.918Z,1742314404.918 [CommandExec](IMPORTANT): Deactivating strobe
2025-03-18T16:13:30.454Z,1742314410.454 [SBIT](IMPORTANT): Beginning Startup BIT
2025-03-18T16:13:30.459Z,1742314410.459 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-03-18T16:13:35.041Z,1742314415.041 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.111839
CHAN A1 (24V): 0.000719
CHAN A2 (12V): 0.000107
CHAN A3 (5V): -0.001439
CHAN B0 (3.3V): 0.000397
CHAN B1 (3.15aV): 0.000220
CHAN B2 (3.15bV): -0.000310
CHAN B3 (GND): -0.000395
OPEN: 0.005311
Full Scale: +/- 1 mA
2025-03-18T16:14:24.243Z,1742314464.243 [SBIT](IMPORTANT): SBIT PASSED
2025-03-18T16:14:24.243Z,1742314464.243 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-03-18T16:14:24.244Z,1742314464.244 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=12 count;
2025-03-18T16:14:24.244Z,1742314464.244 [SBIT](IMPORTANT): CBIT.abortDepth=305 meter;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): CBIT.stopDepth=295 meter;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=5 minute;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): Express linearApproximation PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 100.000000 micromole_per_second_per_square_meter;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 1.000000 count_per_second;
2025-03-18T16:14:24.245Z,1742314464.245 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 25.000000 count_per_second;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_caseHumidity 10.000000 percent;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): Express none _.planktivore_diatoms;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): Express none _.planktivore_dinoflagellates;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): Express none _.predict_plankton_data_pct_dinos_sqerr;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;
2025-03-18T16:14:24.246Z,1742314464.246 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): MassServo.loadAtStartup=1 bool;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): Normal all _.planktivore_diatoms;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): Normal all _.planktivore_dinoflagellates;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): Normal linearApproximation _.predict_plankton_data_pct_dinos_sqerr 0.100000 none;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): ThrusterHE.bestEffortMode=0 bool;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=286.339339 cubic_centimeter;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): VerticalControl.massDefault=15.558109 millimeter;
2025-03-18T16:14:24.247Z,1742314464.247 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;
2025-03-18T16:14:24.635Z,1742314464.635 [MissionManager](IMPORTANT): Started mission Startup
2025-03-18T16:14:24.635Z,1742314464.635 [Startup] Running Loop=1
2025-03-18T16:14:24.636Z,1742314464.636 [Startup](DEBUG): Aggregate::initialize Startup
2025-03-18T16:14:24.636Z,1742314464.636 [Startup:A.GoToSurface] Running Loop=1
2025-03-18T16:14:24.636Z,1742314464.636 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-18T16:14:24.637Z,1742314464.637 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-18T16:14:24.637Z,1742314464.637 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-18T16:14:24.637Z,1742314464.637 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-18T16:14:24.638Z,1742314464.638 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-18T16:14:24.638Z,1742314464.638 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-18T16:14:24.638Z,1742314464.638 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-18T16:14:24.664Z,1742314464.664 [Startup:StartupSatComms] Running Loop=1
2025-03-18T16:14:24.664Z,1742314464.664 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-03-18T16:14:24.665Z,1742314464.665 [Startup:StartupSatComms:A] Running Loop=1
2025-03-18T16:14:25.044Z,1742314465.044 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-03-18T16:14:50.042Z,1742314490.042 [CommandExec](IMPORTANT): got command strobe off
2025-03-18T16:14:50.042Z,1742314490.042 [CommandExec](IMPORTANT): Deactivating strobe
2025-03-18T16:15:08.265Z,1742314508.265 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-03-18T16:15:08.265Z,1742314508.265 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:15:08.292Z,1742314508.292 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:15:08.679Z,1742314508.679 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:15:08.679Z,1742314508.679 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-03-18T16:15:24.838Z,1742314524.838 [Startup:StartupSatComms:A](INFO): Timed out from 2025-03-18T16:14:24.7Z
2025-03-18T16:15:24.838Z,1742314524.838 [Startup:StartupSatComms:A] Stopped
2025-03-18T16:15:24.838Z,1742314524.838 [Startup:StartupSatComms:B] Running Loop=1
2025-03-18T16:15:25.242Z,1742314525.242 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-18T16:15:32.429Z,1742314532.429 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250313T165627/Courier0244.lzma
2025-03-18T16:15:33.431Z,1742314533.431 [DataOverHttps](INFO): Moved sent file to Logs/20250313T165627/Courier0244.lzma.bak
2025-03-18T16:15:33.431Z,1742314533.431 [DataOverHttps](INFO): SBD MOMSN=24371331
2025-03-18T16:15:48.936Z,1742314548.936 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20250318T161156/Courier0000.lzma
2025-03-18T16:15:49.950Z,1742314549.950 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0000.lzma.bak
2025-03-18T16:15:49.950Z,1742314549.950 [DataOverHttps](INFO): SBD MOMSN=24371333
2025-03-18T16:16:05.477Z,1742314565.477 [DataOverHttps](INFO): Sending 110 bytes from file Logs/20250313T165627/Express0245.lzma
2025-03-18T16:16:06.479Z,1742314566.479 [DataOverHttps](INFO): Moved sent file to Logs/20250313T165627/Express0245.lzma.bak
2025-03-18T16:16:06.479Z,1742314566.479 [DataOverHttps](INFO): SBD MOMSN=24371338
2025-03-18T16:16:21.956Z,1742314581.956 [DataOverHttps](INFO): Sending 1468 bytes from file Logs/20250318T161156/Express0001.lzma
2025-03-18T16:16:22.954Z,1742314582.954 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0001.lzma.bak
2025-03-18T16:16:22.954Z,1742314582.954 [DataOverHttps](INFO): SBD MOMSN=24371341
2025-03-18T16:16:24.217Z,1742314584.217 [Startup:StartupSatComms:B] Stopped
2025-03-18T16:16:24.218Z,1742314584.218 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-03-18T16:16:24.218Z,1742314584.218 [Startup:StartupSatComms] Stopped
2025-03-18T16:16:24.218Z,1742314584.218 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-03-18T16:16:24.219Z,1742314584.219 [Startup](INFO): Completed Startup
2025-03-18T16:16:24.219Z,1742314584.219 [MissionManager](INFO): Startup is completed.
2025-03-18T16:16:24.219Z,1742314584.219 [MissionManager](INFO): Uninitializing Mission Startup
2025-03-18T16:16:24.219Z,1742314584.219 [Startup] Stopped
2025-03-18T16:16:24.219Z,1742314584.219 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-03-18T16:16:24.219Z,1742314584.219 [Startup:A.GoToSurface] Stopped
2025-03-18T16:16:24.219Z,1742314584.219 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-18T16:16:24.626Z,1742314584.626 [MissionManager](IMPORTANT): Started mission Default
2025-03-18T16:16:24.626Z,1742314584.626 [Default] Running Loop=1
2025-03-18T16:16:24.626Z,1742314584.626 [Default](DEBUG): Aggregate::initialize Default
2025-03-18T16:16:24.627Z,1742314584.627 [Default:B.GoToSurface] Running Loop=1
2025-03-18T16:16:24.627Z,1742314584.627 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-18T16:16:24.627Z,1742314584.627 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-18T16:16:24.627Z,1742314584.627 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-18T16:16:24.627Z,1742314584.627 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-18T16:16:24.628Z,1742314584.628 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-18T16:16:24.628Z,1742314584.628 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-18T16:16:24.629Z,1742314584.629 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-18T16:16:24.629Z,1742314584.629 [Default:A.Wait] Running Loop=1
2025-03-18T16:16:24.629Z,1742314584.629 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-18T16:16:37.963Z,1742314597.963 [Default:A.Wait](INFO): Done Waiting.
2025-03-18T16:16:37.963Z,1742314597.963 [Default:A.Wait] Stopped
2025-03-18T16:16:37.963Z,1742314597.963 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T16:16:38.373Z,1742314598.373 [Default:CheckIn] Running Loop=1
2025-03-18T16:16:38.373Z,1742314598.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T16:16:38.373Z,1742314598.373 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T16:16:38.767Z,1742314598.767 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-18T16:17:09.046Z,1742314629.046 [BPC1](FAULT): Failed to initialize
2025-03-18T16:17:09.046Z,1742314629.046 [BPC1] Communications Fault, FailCount= 1
2025-03-18T16:17:09.046Z,1742314629.046 [BPC1](ERROR): Communications Fault
2025-03-18T16:17:09.115Z,1742314629.115 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T16:17:51.069Z,1742314671.069 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T16:18:09.267Z,1742314689.267 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-03-18T16:18:09.267Z,1742314689.267 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:18:09.278Z,1742314689.278 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:18:09.696Z,1742314689.696 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:18:09.696Z,1742314689.696 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-03-18T16:21:06.594Z,1742314866.594 [CommandExec](IMPORTANT): got command strobe off
2025-03-18T16:21:06.594Z,1742314866.594 [CommandExec](IMPORTANT): Deactivating strobe
2025-03-18T16:21:10.335Z,1742314870.335 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-03-18T16:21:10.335Z,1742314870.335 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:21:10.355Z,1742314870.355 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:21:10.763Z,1742314870.763 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:21:10.763Z,1742314870.763 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-03-18T16:21:38.591Z,1742314898.591 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-18T16:16:38.4Z
2025-03-18T16:21:38.591Z,1742314898.591 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T16:21:38.591Z,1742314898.591 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T16:21:39.003Z,1742314899.003 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-18T16:21:45.688Z,1742314905.688 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250318T161156/Courier0004.lzma
2025-03-18T16:21:46.690Z,1742314906.690 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0004.lzma.bak
2025-03-18T16:21:46.690Z,1742314906.690 [DataOverHttps](INFO): SBD MOMSN=24371393
2025-03-18T16:22:02.228Z,1742314922.228 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20250318T161156/Express0005.lzma
2025-03-18T16:22:03.230Z,1742314923.230 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0005.lzma.bak
2025-03-18T16:22:03.230Z,1742314923.230 [DataOverHttps](INFO): SBD MOMSN=24371395
2025-03-18T16:22:04.868Z,1742314924.868 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T16:22:04.868Z,1742314924.868 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T16:22:04.868Z,1742314924.868 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T16:22:15.813Z,1742314935.813 [CommandExec](IMPORTANT): got command gfscan
2025-03-18T16:22:16.197Z,1742314936.197 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-03-18T16:22:20.627Z,1742314940.627 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.113880
CHAN A1 (24V): 0.001094
CHAN A2 (12V): 0.000118
CHAN A3 (5V): -0.001725
CHAN B0 (3.3V): 0.000276
CHAN B1 (3.15aV): -0.000143
CHAN B2 (3.15bV): 0.000292
CHAN B3 (GND): -0.000259
OPEN: 0.005267
Full Scale: +/- 1 mA
2025-03-18T16:22:46.469Z,1742314966.469 [Power24vConverter](INFO): Powering down.
2025-03-18T16:22:49.286Z,1742314969.286 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-18T16:22:49.286Z,1742314969.286 [NAL9602] Data Fault, FailCount= 1
2025-03-18T16:22:49.286Z,1742314969.286 [NAL9602](ERROR): Data Fault
2025-03-18T16:22:49.305Z,1742314969.305 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-18T16:22:49.685Z,1742314969.685 [NAL9602](INFO): Powering down
2025-03-18T16:22:50.515Z,1742314970.515 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-18T16:22:50.515Z,1742314970.515 [NAL9602] No Fault, FailCount= 1
2025-03-18T16:23:19.986Z,1742314999.986 [NAL9602](INFO): Powering up NAL9602
2025-03-18T16:23:30.897Z,1742315010.897 [NAL9602](INFO): NAL9602 initialized
2025-03-18T16:24:11.310Z,1742315051.310 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-03-18T16:24:11.310Z,1742315051.310 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:24:11.353Z,1742315051.353 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:24:11.719Z,1742315051.719 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:24:11.719Z,1742315051.719 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-03-18T16:27:05.444Z,1742315225.444 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T16:27:05.444Z,1742315225.444 [Default:CheckIn:C.Wait] Stopped
2025-03-18T16:27:05.444Z,1742315225.444 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T16:27:05.444Z,1742315225.444 [Default:CheckIn:D] Running Loop=1
2025-03-18T16:27:05.866Z,1742315225.866 [Default:CheckIn:D] Stopped
2025-03-18T16:27:05.866Z,1742315225.866 [Default:CheckIn:E] Running Loop=1
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.687321 min
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn:E] Stopped
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn] Stopped
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn](INFO): Running loop #2
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn] Running Loop=2
2025-03-18T16:27:06.259Z,1742315226.259 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T16:27:06.260Z,1742315226.260 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T16:27:09.104Z,1742315229.104 [CBIT](INFO): Clearing failed state for component DropWeight
2025-03-18T16:27:09.104Z,1742315229.104 [DropWeight] No Fault, FailCount= 1
2025-03-18T16:27:09.908Z,1742315229.908 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T16:27:09.928Z,1742315229.928 [BPC1] No Fault, FailCount= 1
2025-03-18T16:27:12.326Z,1742315232.326 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-03-18T16:27:12.326Z,1742315232.326 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:27:12.349Z,1742315232.349 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:27:12.724Z,1742315232.724 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:27:12.724Z,1742315232.724 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-03-18T16:29:41.392Z,1742315381.392 [CommandExec](IMPORTANT): got command failComponent
2025-03-18T16:29:41.392Z,1742315381.392 [CommandExec](IMPORTANT): Failed components:
2025-03-18T16:29:41.393Z,1742315381.393 [CommandExec](IMPORTANT): No failed Components.
2025-03-18T16:30:00.582Z,1742315400.582 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC7
2025-03-18T16:30:05.886Z,1742315405.886 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC6
2025-03-18T16:30:07.554Z,1742315407.554 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC5
2025-03-18T16:30:09.218Z,1742315409.218 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC4
2025-03-18T16:30:09.639Z,1742315409.639 [AHRS_M2](FAULT): LCB fault: Current Limiter Activated.
2025-03-18T16:30:09.639Z,1742315409.639 [AHRS_M2] Hardware Fault, FailCount= 1
2025-03-18T16:30:09.639Z,1742315409.639 [AHRS_M2](ERROR): Hardware Fault
2025-03-18T16:30:09.691Z,1742315409.691 [CBIT](ERROR): Hardware Fault in component: AHRS_M2
2025-03-18T16:30:10.042Z,1742315410.042 [AHRS_M2](INFO): Powering down
2025-03-18T16:30:10.448Z,1742315410.448 [AHRS_M2](FAULT): LCB fault: Current Limiter Activated.
2025-03-18T16:30:10.891Z,1742315410.891 [CBIT](INFO): Clearing failed state for component AHRS_M2
2025-03-18T16:30:10.892Z,1742315410.892 [AHRS_M2] No Fault, FailCount= 1
2025-03-18T16:30:11.254Z,1742315411.254 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-03-18T16:30:13.308Z,1742315413.308 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-03-18T16:30:13.308Z,1742315413.308 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:30:13.357Z,1742315413.357 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:30:13.746Z,1742315413.746 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:30:13.746Z,1742315413.746 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-03-18T16:30:20.046Z,1742315420.046 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC3
2025-03-18T16:30:21.918Z,1742315421.918 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC2
2025-03-18T16:30:23.582Z,1742315423.582 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC1
2025-03-18T16:30:27.430Z,1742315427.430 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC0
2025-03-18T16:30:30.345Z,1742315430.345 [CommandExec](IMPORTANT): got command gfscan
2025-03-18T16:30:30.706Z,1742315430.706 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-03-18T16:30:31.917Z,1742315431.917 [GFScanner](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2025-03-18T16:30:35.147Z,1742315435.147 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.113983
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.000080
CHAN A3 (5V): -0.001372
CHAN B0 (3.3V): 0.000278
CHAN B1 (3.15aV): -0.000132
CHAN B2 (3.15bV): -0.000026
CHAN B3 (GND): -0.000771
OPEN: 0.004659
Full Scale: +/- 1 mA
2025-03-18T16:30:42.318Z,1742315442.318 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB5
2025-03-18T16:30:44.458Z,1742315444.458 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2025-03-18T16:30:46.250Z,1742315446.250 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB3
2025-03-18T16:30:48.022Z,1742315448.022 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB2
2025-03-18T16:30:49.894Z,1742315449.894 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB1
2025-03-18T16:30:52.190Z,1742315452.190 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB0
2025-03-18T16:30:55.209Z,1742315455.209 [CommandExec](IMPORTANT): got command gfscan
2025-03-18T16:30:55.301Z,1742315455.301 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.749329 decibar, -0.743803 m
2025-03-18T16:30:55.349Z,1742315455.349 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-03-18T16:30:56.131Z,1742315456.131 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -21.00 mm (1 active estimators).
2025-03-18T16:30:56.514Z,1742315456.514 [Power24vConverter](INFO): Powering up.
2025-03-18T16:30:56.912Z,1742315456.912 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.395090 decibar, -1.384803 m
2025-03-18T16:30:58.975Z,1742315458.975 [Depth_Keller](FAULT): Pressure or depth reading out of range for max 5 samples
2025-03-18T16:30:58.975Z,1742315458.975 [Depth_Keller] Data Fault, FailCount= 1
2025-03-18T16:30:58.975Z,1742315458.975 [Depth_Keller](ERROR): Data Fault
2025-03-18T16:30:59.073Z,1742315459.073 [CBIT](ERROR): Data Fault in component: Depth_Keller
2025-03-18T16:30:59.073Z,1742315459.073 [CBIT](INFO): Clearing failed state for component Depth_Keller
2025-03-18T16:30:59.073Z,1742315459.073 [Depth_Keller] No Fault, FailCount= 1
2025-03-18T16:30:59.781Z,1742315459.781 [Depth_Keller](ERROR): Pressure or depth reading out of range: -4.949864 decibar, -4.913408 m
2025-03-18T16:30:59.880Z,1742315459.880 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.112880
CHAN A1 (24V): 0.000053
CHAN A2 (12V): -0.000400
CHAN A3 (5V): -0.001660
CHAN B0 (3.3V): -0.000049
CHAN B1 (3.15aV): -0.000081
CHAN B2 (3.15bV): -0.000005
CHAN B3 (GND): -0.000200
OPEN: 0.001207
Full Scale: +/- 1 mA
2025-03-18T16:31:10.122Z,1742315470.122 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA7
2025-03-18T16:31:11.896Z,1742315471.896 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA6
2025-03-18T16:31:13.470Z,1742315473.470 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA5
2025-03-18T16:31:33.817Z,1742315493.817 [Waterlinked](INFO): Powering down
2025-03-18T16:32:06.456Z,1742315526.456 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-18T16:27:06.3Z
2025-03-18T16:32:06.456Z,1742315526.456 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T16:32:06.457Z,1742315526.457 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T16:32:10.478Z,1742315530.478 [BPC1](FAULT): Failed to initialize
2025-03-18T16:32:10.478Z,1742315530.478 [BPC1] Communications Fault, FailCount= 2
2025-03-18T16:32:10.478Z,1742315530.478 [BPC1](ERROR): Communications Fault
2025-03-18T16:32:10.555Z,1742315530.555 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T16:32:13.652Z,1742315533.652 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250318T161156/Courier0007.lzma
2025-03-18T16:32:14.654Z,1742315534.654 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0007.lzma.bak
2025-03-18T16:32:14.654Z,1742315534.654 [DataOverHttps](INFO): SBD MOMSN=24371414
2025-03-18T16:32:30.174Z,1742315550.174 [DataOverHttps](INFO): Sending 834 bytes from file Logs/20250318T161156/Express0008.lzma
2025-03-18T16:32:31.174Z,1742315551.174 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0008.lzma.bak
2025-03-18T16:32:31.174Z,1742315551.174 [DataOverHttps](INFO): SBD MOMSN=24371416
2025-03-18T16:32:32.731Z,1742315552.731 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T16:32:32.731Z,1742315552.731 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T16:32:32.731Z,1742315552.731 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T16:33:14.331Z,1742315594.331 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-03-18T16:33:14.331Z,1742315594.331 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:33:14.342Z,1742315594.342 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:33:14.755Z,1742315594.755 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:33:14.755Z,1742315594.755 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-03-18T16:33:32.094Z,1742315612.094 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-18T16:33:32.094Z,1742315612.094 [NAL9602] Data Fault, FailCount= 2
2025-03-18T16:33:32.094Z,1742315612.094 [NAL9602](ERROR): Data Fault
2025-03-18T16:33:32.112Z,1742315612.112 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-18T16:33:32.494Z,1742315612.494 [NAL9602](INFO): Powering down
2025-03-18T16:33:33.323Z,1742315613.323 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-18T16:33:33.323Z,1742315613.323 [NAL9602] No Fault, FailCount= 2
2025-03-18T16:34:02.798Z,1742315642.798 [NAL9602](INFO): Powering up NAL9602
2025-03-18T16:34:13.706Z,1742315653.706 [NAL9602](INFO): NAL9602 initialized
2025-03-18T16:36:15.330Z,1742315775.330 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-03-18T16:36:15.330Z,1742315775.330 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:36:15.341Z,1742315775.341 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:36:15.751Z,1742315775.751 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:36:15.751Z,1742315775.751 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-03-18T16:37:33.290Z,1742315853.290 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T16:37:33.290Z,1742315853.290 [Default:CheckIn:C.Wait] Stopped
2025-03-18T16:37:33.291Z,1742315853.291 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T16:37:33.291Z,1742315853.291 [Default:CheckIn:D] Running Loop=1
2025-03-18T16:37:33.698Z,1742315853.698 [Default:CheckIn:D] Stopped
2025-03-18T16:37:33.698Z,1742315853.698 [Default:CheckIn:E] Running Loop=1
2025-03-18T16:37:34.112Z,1742315854.112 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.151196 min
2025-03-18T16:37:34.112Z,1742315854.112 [Default:CheckIn:E] Stopped
2025-03-18T16:37:34.113Z,1742315854.113 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T16:37:34.113Z,1742315854.113 [Default:CheckIn] Stopped
2025-03-18T16:37:34.113Z,1742315854.113 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T16:37:34.113Z,1742315854.113 [Default:CheckIn](INFO): Running loop #3
2025-03-18T16:37:34.113Z,1742315854.113 [Default:CheckIn] Running Loop=3
2025-03-18T16:37:34.113Z,1742315854.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T16:37:34.113Z,1742315854.113 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T16:39:16.327Z,1742315956.327 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-03-18T16:39:16.327Z,1742315956.327 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-18T16:39:16.338Z,1742315956.338 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-18T16:39:16.743Z,1742315956.743 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-18T16:39:16.743Z,1742315956.743 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-03-18T16:39:40.943Z,1742315980.943 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163939.00,A,3648.17402,N,12147.27435,W,0.019,0.00,180325,,,A*71
2025-03-18T16:39:40.947Z,1742315980.947 [NAL9602](INFO): GPS fix at 20250318T163939: (36.802900, -121.787906)
2025-03-18T16:39:40.999Z,1742315980.999 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T16:39:40.999Z,1742315980.999 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T16:39:42.615Z,1742315982.615 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20250318T161156/Courier0010.lzma
2025-03-18T16:39:43.506Z,1742315983.506 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0010.lzma.bak
2025-03-18T16:39:43.506Z,1742315983.506 [DataOverHttps](INFO): SBD MOMSN=24371458
2025-03-18T16:40:00.465Z,1742316000.465 [DataOverHttps](INFO): Sending 414 bytes from file Logs/20250318T161156/Express0011.lzma
2025-03-18T16:40:01.466Z,1742316001.466 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0011.lzma.bak
2025-03-18T16:40:01.466Z,1742316001.466 [DataOverHttps](INFO): SBD MOMSN=24371461
2025-03-18T16:40:02.916Z,1742316002.916 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T16:40:02.916Z,1742316002.916 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T16:40:02.916Z,1742316002.916 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T16:40:13.416Z,1742316013.416 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T16:41:34.613Z,1742316094.613 [Power24vConverter](INFO): Powering down.
2025-03-18T16:42:11.413Z,1742316131.413 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T16:42:11.413Z,1742316131.413 [BPC1] No Fault, FailCount= 2
2025-03-18T16:45:03.498Z,1742316303.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T16:45:03.498Z,1742316303.498 [Default:CheckIn:C.Wait] Stopped
2025-03-18T16:45:03.498Z,1742316303.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T16:45:03.498Z,1742316303.498 [Default:CheckIn:D] Running Loop=1
2025-03-18T16:45:03.915Z,1742316303.915 [Default:CheckIn:D] Stopped
2025-03-18T16:45:03.915Z,1742316303.915 [Default:CheckIn:E] Running Loop=1
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.654814 min
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn:E] Stopped
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn] Stopped
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn](INFO): Running loop #4
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn] Running Loop=4
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T16:45:04.305Z,1742316304.305 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T16:45:06.323Z,1742316306.323 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164505.00,A,3648.16754,N,12147.27636,W,1.322,0.00,180325,,,A*7F
2025-03-18T16:45:06.327Z,1742316306.327 [NAL9602](INFO): GPS fix at 20250318T164505: (36.802792, -121.787939)
2025-03-18T16:45:06.342Z,1742316306.342 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T16:45:06.342Z,1742316306.342 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T16:45:13.628Z,1742316313.628 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0013.lzma
2025-03-18T16:45:14.630Z,1742316314.630 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0013.lzma.bak
2025-03-18T16:45:14.630Z,1742316314.630 [DataOverHttps](INFO): SBD MOMSN=24371472
2025-03-18T16:45:30.948Z,1742316330.948 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20250318T161156/Express0014.lzma
2025-03-18T16:45:31.950Z,1742316331.950 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0014.lzma.bak
2025-03-18T16:45:31.950Z,1742316331.950 [DataOverHttps](INFO): SBD MOMSN=24371475
2025-03-18T16:45:33.409Z,1742316333.409 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T16:45:33.409Z,1742316333.409 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T16:45:33.409Z,1742316333.409 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T16:47:11.002Z,1742316431.002 [DataOverHttps](IMPORTANT): SBD MTMSN=20250318T164710
2025-03-18T16:47:11.958Z,1742316431.958 [BPC1](FAULT): Failed to initialize
2025-03-18T16:47:11.958Z,1742316431.958 [BPC1] Communications Fault, FailCount= 3
2025-03-18T16:47:11.958Z,1742316431.958 [BPC1](ERROR): Communications Fault
2025-03-18T16:47:11.985Z,1742316431.985 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T16:47:18.538Z,1742316438.538 [DataOverHttps](INFO): Received command: failc
2025-03-18T16:50:08.121Z,1742316608.121 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T16:50:33.988Z,1742316633.988 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T16:50:33.988Z,1742316633.988 [Default:CheckIn:C.Wait] Stopped
2025-03-18T16:50:33.988Z,1742316633.988 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T16:50:33.988Z,1742316633.988 [Default:CheckIn:D] Running Loop=1
2025-03-18T16:50:34.392Z,1742316634.392 [Default:CheckIn:D] Stopped
2025-03-18T16:50:34.392Z,1742316634.392 [Default:CheckIn:E] Running Loop=1
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.162760 min
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn:E] Stopped
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn] Stopped
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn](INFO): Running loop #5
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn] Running Loop=5
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T16:50:34.798Z,1742316634.798 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T16:50:36.807Z,1742316636.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165036.00,A,3648.14995,N,12147.27957,W,0.680,155.30,180325,,,A*7C
2025-03-18T16:50:36.819Z,1742316636.819 [NAL9602](INFO): GPS fix at 20250318T165036: (36.802499, -121.787993)
2025-03-18T16:50:36.830Z,1742316636.830 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T16:50:36.830Z,1742316636.830 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T16:50:43.716Z,1742316643.716 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0016.lzma
2025-03-18T16:50:44.718Z,1742316644.718 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0016.lzma.bak
2025-03-18T16:50:44.718Z,1742316644.718 [DataOverHttps](INFO): SBD MOMSN=24371486
2025-03-18T16:51:02.733Z,1742316662.733 [DataOverHttps](INFO): Sending 347 bytes from file Logs/20250318T161156/Express0017.lzma
2025-03-18T16:51:03.734Z,1742316663.734 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0017.lzma.bak
2025-03-18T16:51:03.734Z,1742316663.734 [DataOverHttps](INFO): SBD MOMSN=24371489
2025-03-18T16:51:05.548Z,1742316665.548 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T16:51:05.548Z,1742316665.548 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T16:51:05.548Z,1742316665.548 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T16:51:09.579Z,1742316669.579 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T16:56:06.138Z,1742316966.138 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T16:56:06.138Z,1742316966.138 [Default:CheckIn:C.Wait] Stopped
2025-03-18T16:56:06.138Z,1742316966.138 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T16:56:06.138Z,1742316966.138 [Default:CheckIn:D] Running Loop=1
2025-03-18T16:56:06.529Z,1742316966.529 [Default:CheckIn:D] Stopped
2025-03-18T16:56:06.529Z,1742316966.529 [Default:CheckIn:E] Running Loop=1
2025-03-18T16:56:06.932Z,1742316966.932 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.698381 min
2025-03-18T16:56:06.932Z,1742316966.932 [Default:CheckIn:E] Stopped
2025-03-18T16:56:06.932Z,1742316966.932 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T16:56:06.932Z,1742316966.932 [Default:CheckIn] Stopped
2025-03-18T16:56:06.932Z,1742316966.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T16:56:06.932Z,1742316966.932 [Default:CheckIn](INFO): Running loop #6
2025-03-18T16:56:06.932Z,1742316966.932 [Default:CheckIn] Running Loop=6
2025-03-18T16:56:06.933Z,1742316966.933 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T16:56:06.933Z,1742316966.933 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T16:56:08.941Z,1742316968.941 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165608.00,A,3648.15883,N,12147.27933,W,1.749,358.10,180325,,,A*7A
2025-03-18T16:56:08.943Z,1742316968.943 [NAL9602](INFO): GPS fix at 20250318T165608: (36.802647, -121.787989)
2025-03-18T16:56:08.954Z,1742316968.954 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T16:56:08.954Z,1742316968.954 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T16:56:16.528Z,1742316976.528 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250318T161156/Courier0019.lzma
2025-03-18T16:56:17.530Z,1742316977.530 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0019.lzma.bak
2025-03-18T16:56:17.530Z,1742316977.530 [DataOverHttps](INFO): SBD MOMSN=24371501
2025-03-18T16:56:33.232Z,1742316993.232 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20250318T161156/Express0021.lzma
2025-03-18T16:56:34.234Z,1742316994.234 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0021.lzma.bak
2025-03-18T16:56:34.234Z,1742316994.234 [DataOverHttps](INFO): SBD MOMSN=24371504
2025-03-18T16:56:35.624Z,1742316995.624 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T16:56:35.624Z,1742316995.624 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T16:56:35.624Z,1742316995.624 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T16:56:39.641Z,1742316999.641 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-18T16:56:39.716Z,1742316999.716 [NAL9602](ERROR): received:
+CSQ:0
OK
2025-03-18T16:57:10.357Z,1742317030.357 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-03-18T16:57:10.357Z,1742317030.357 [DropWeight] Hardware Fault, FailCount= 1
2025-03-18T16:57:10.357Z,1742317030.357 [DropWeight](ERROR): Hardware Fault
2025-03-18T16:57:10.413Z,1742317030.413 [CBIT](INFO): Critical error at 20250318T165710
2025-03-18T16:57:10.415Z,1742317030.415 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-03-18T16:57:10.415Z,1742317030.415 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-03-18T16:57:10.783Z,1742317030.783 [CBIT](INFO): Critical error at 20250318T165710
2025-03-18T16:57:12.866Z,1742317032.866 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T16:57:12.866Z,1742317032.866 [BPC1] No Fault, FailCount= 3
2025-03-18T17:01:11.534Z,1742317271.534 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T17:01:36.236Z,1742317296.236 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:01:36.237Z,1742317296.237 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:01:36.237Z,1742317296.237 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:01:36.237Z,1742317296.237 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:01:36.654Z,1742317296.654 [Default:CheckIn:D] Stopped
2025-03-18T17:01:36.654Z,1742317296.654 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:01:37.019Z,1742317297.019 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.200452 min
2025-03-18T17:01:37.019Z,1742317297.019 [Default:CheckIn:E] Stopped
2025-03-18T17:01:37.019Z,1742317297.019 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:01:37.019Z,1742317297.019 [Default:CheckIn] Stopped
2025-03-18T17:01:37.019Z,1742317297.019 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:01:37.019Z,1742317297.019 [Default:CheckIn](INFO): Running loop #7
2025-03-18T17:01:37.019Z,1742317297.019 [Default:CheckIn] Running Loop=7
2025-03-18T17:01:37.020Z,1742317297.020 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:01:37.020Z,1742317297.020 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:01:39.007Z,1742317299.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170138.00,A,3648.15974,N,12147.27210,W,0.194,135.91,180325,,,A*7E
2025-03-18T17:01:39.009Z,1742317299.009 [NAL9602](INFO): GPS fix at 20250318T170138: (36.802662, -121.787868)
2025-03-18T17:01:39.020Z,1742317299.020 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:01:39.021Z,1742317299.021 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:01:46.240Z,1742317306.240 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250318T161156/Courier0025.lzma
2025-03-18T17:01:47.242Z,1742317307.242 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0025.lzma.bak
2025-03-18T17:01:47.242Z,1742317307.242 [DataOverHttps](INFO): SBD MOMSN=24371513
2025-03-18T17:02:03.292Z,1742317323.292 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20250318T161156/Express0026.lzma
2025-03-18T17:02:04.294Z,1742317324.294 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0026.lzma.bak
2025-03-18T17:02:04.295Z,1742317324.295 [DataOverHttps](INFO): SBD MOMSN=24371518
2025-03-18T17:02:05.688Z,1742317325.688 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:02:05.688Z,1742317325.688 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:02:05.689Z,1742317325.689 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:02:11.329Z,1742317331.329 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T17:02:13.344Z,1742317333.344 [BPC1](FAULT): Failed to initialize
2025-03-18T17:02:13.344Z,1742317333.344 [BPC1] Communications Fault, FailCount= 4
2025-03-18T17:02:13.344Z,1742317333.344 [BPC1](ERROR): Communications Fault
2025-03-18T17:02:13.368Z,1742317333.368 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T17:07:06.305Z,1742317626.305 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:07:06.305Z,1742317626.305 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:07:06.305Z,1742317626.305 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:07:06.305Z,1742317626.305 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:07:06.718Z,1742317626.718 [Default:CheckIn:D] Stopped
2025-03-18T17:07:06.718Z,1742317626.718 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:07:07.104Z,1742317627.104 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.701530 min
2025-03-18T17:07:07.104Z,1742317627.104 [Default:CheckIn:E] Stopped
2025-03-18T17:07:07.104Z,1742317627.104 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:07:07.104Z,1742317627.104 [Default:CheckIn] Stopped
2025-03-18T17:07:07.104Z,1742317627.104 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:07:07.105Z,1742317627.105 [Default:CheckIn](INFO): Running loop #8
2025-03-18T17:07:07.105Z,1742317627.105 [Default:CheckIn] Running Loop=8
2025-03-18T17:07:07.105Z,1742317627.105 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:07:07.105Z,1742317627.105 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:07:09.143Z,1742317629.143 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170708.00,A,3648.16485,N,12147.27453,W,0.253,57.41,180325,,,A*4A
2025-03-18T17:07:09.145Z,1742317629.145 [NAL9602](INFO): GPS fix at 20250318T170708: (36.802748, -121.787909)
2025-03-18T17:07:09.197Z,1742317629.197 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:07:09.198Z,1742317629.198 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:07:17.216Z,1742317637.216 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250318T161156/Courier0028.lzma
2025-03-18T17:07:18.218Z,1742317638.218 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0028.lzma.bak
2025-03-18T17:07:18.218Z,1742317638.218 [DataOverHttps](INFO): SBD MOMSN=24371528
2025-03-18T17:07:34.028Z,1742317654.028 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250318T161156/Express0029.lzma
2025-03-18T17:07:35.030Z,1742317655.030 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0029.lzma.bak
2025-03-18T17:07:35.030Z,1742317655.030 [DataOverHttps](INFO): SBD MOMSN=24371534
2025-03-18T17:07:36.601Z,1742317656.601 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:07:36.601Z,1742317656.601 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:07:36.601Z,1742317656.601 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:07:39.818Z,1742317659.818 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-18T17:07:39.896Z,1742317659.896 [NAL9602](ERROR): received:
+CSQ:0
OK
2025-03-18T17:11:18.793Z,1742317878.793 [NAL9602](INFO): SBD MO Status=2, MOMSN=22217, MT Status=2, MTMSN=0
2025-03-18T17:11:18.793Z,1742317878.793 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-18T17:12:08.915Z,1742317928.915 [CBIT](FAULT): Main Battery Failure
2025-03-18T17:12:10.535Z,1742317930.535 [CBIT](INFO): Clearing failed state for component DropWeight
2025-03-18T17:12:10.535Z,1742317930.535 [DropWeight] No Fault, FailCount= 1
2025-03-18T17:12:14.617Z,1742317934.617 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T17:12:14.617Z,1742317934.617 [BPC1] No Fault, FailCount= 4
2025-03-18T17:12:16.563Z,1742317936.563 [NAL9602](INFO): SBD MO Status=2, MOMSN=22217, MT Status=2, MTMSN=0
2025-03-18T17:12:16.563Z,1742317936.563 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-18T17:12:16.966Z,1742317936.966 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T17:12:37.176Z,1742317957.176 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:12:37.176Z,1742317957.176 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:12:37.176Z,1742317957.176 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:12:37.177Z,1742317957.177 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:12:37.583Z,1742317957.583 [Default:CheckIn:D] Stopped
2025-03-18T17:12:37.583Z,1742317957.583 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:12:38.001Z,1742317958.001 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.215938 min
2025-03-18T17:12:38.001Z,1742317958.001 [Default:CheckIn:E] Stopped
2025-03-18T17:12:38.002Z,1742317958.002 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:12:38.002Z,1742317958.002 [Default:CheckIn] Stopped
2025-03-18T17:12:38.002Z,1742317958.002 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:12:38.002Z,1742317958.002 [Default:CheckIn](INFO): Running loop #9
2025-03-18T17:12:38.002Z,1742317958.002 [Default:CheckIn] Running Loop=9
2025-03-18T17:12:38.002Z,1742317958.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:12:38.002Z,1742317958.002 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:12:39.998Z,1742317959.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171239.00,A,3648.16744,N,12147.27894,W,1.225,0.00,180325,,,A*72
2025-03-18T17:12:39.000Z,1742317960.000 [NAL9602](INFO): GPS fix at 20250318T171239: (36.802791, -121.787982)
2025-03-18T17:12:40.035Z,1742317960.035 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:12:40.035Z,1742317960.035 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:12:46.140Z,1742317966.140 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0031.lzma
2025-03-18T17:12:47.138Z,1742317967.138 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0031.lzma.bak
2025-03-18T17:12:47.138Z,1742317967.138 [DataOverHttps](INFO): SBD MOMSN=24371541
2025-03-18T17:13:02.941Z,1742317982.941 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20250318T161156/Express0032.lzma
2025-03-18T17:13:03.942Z,1742317983.942 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0032.lzma.bak
2025-03-18T17:13:03.942Z,1742317983.942 [DataOverHttps](INFO): SBD MOMSN=24371550
2025-03-18T17:13:05.469Z,1742317985.469 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:13:05.469Z,1742317985.469 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:13:05.469Z,1742317985.469 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:13:12.329Z,1742317992.329 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T17:17:15.128Z,1742318235.128 [BPC1](FAULT): Failed to initialize
2025-03-18T17:17:15.128Z,1742318235.128 [BPC1] Communications Fault, FailCount= 5
2025-03-18T17:17:15.128Z,1742318235.128 [BPC1](ERROR): Communications Fault
2025-03-18T17:17:15.181Z,1742318235.181 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T17:18:06.052Z,1742318286.052 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:18:06.052Z,1742318286.052 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:18:06.052Z,1742318286.052 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:18:06.052Z,1742318286.052 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:18:06.467Z,1742318286.467 [Default:CheckIn:D] Stopped
2025-03-18T17:18:06.467Z,1742318286.467 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:18:06.856Z,1742318286.856 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.697347 min
2025-03-18T17:18:06.856Z,1742318286.856 [Default:CheckIn:E] Stopped
2025-03-18T17:18:06.856Z,1742318286.856 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:18:06.856Z,1742318286.856 [Default:CheckIn] Stopped
2025-03-18T17:18:06.856Z,1742318286.856 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:18:06.857Z,1742318286.857 [Default:CheckIn](INFO): Running loop #10
2025-03-18T17:18:06.857Z,1742318286.857 [Default:CheckIn] Running Loop=10
2025-03-18T17:18:06.857Z,1742318286.857 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:18:06.857Z,1742318286.857 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:18:08.865Z,1742318288.865 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171808.00,A,3648.16558,N,12147.27521,W,0.175,0.00,180325,,,A*71
2025-03-18T17:18:08.867Z,1742318288.867 [NAL9602](INFO): GPS fix at 20250318T171808: (36.802760, -121.787920)
2025-03-18T17:18:08.878Z,1742318288.878 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:18:08.878Z,1742318288.878 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:18:16.120Z,1742318296.120 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250318T161156/Courier0034.lzma
2025-03-18T17:18:17.122Z,1742318297.122 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0034.lzma.bak
2025-03-18T17:18:17.122Z,1742318297.122 [DataOverHttps](INFO): SBD MOMSN=24371559
2025-03-18T17:18:33.016Z,1742318313.016 [DataOverHttps](INFO): Sending 191 bytes from file Logs/20250318T161156/Express0035.lzma
2025-03-18T17:18:34.018Z,1742318314.018 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0035.lzma.bak
2025-03-18T17:18:34.018Z,1742318314.018 [DataOverHttps](INFO): SBD MOMSN=24371564
2025-03-18T17:18:35.548Z,1742318315.548 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:18:35.548Z,1742318315.548 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:18:35.548Z,1742318315.548 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:23:11.482Z,1742318591.482 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T17:23:36.144Z,1742318616.144 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:23:36.144Z,1742318616.144 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:23:36.144Z,1742318616.144 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:23:36.144Z,1742318616.144 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:23:36.532Z,1742318616.532 [Default:CheckIn:D] Stopped
2025-03-18T17:23:36.532Z,1742318616.532 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:23:36.935Z,1742318616.935 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.198425 min
2025-03-18T17:23:36.935Z,1742318616.935 [Default:CheckIn:E] Stopped
2025-03-18T17:23:36.935Z,1742318616.935 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:23:36.935Z,1742318616.935 [Default:CheckIn] Stopped
2025-03-18T17:23:36.935Z,1742318616.935 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:23:36.935Z,1742318616.935 [Default:CheckIn](INFO): Running loop #11
2025-03-18T17:23:36.936Z,1742318616.936 [Default:CheckIn] Running Loop=11
2025-03-18T17:23:36.936Z,1742318616.936 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:23:36.936Z,1742318616.936 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:23:38.947Z,1742318618.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172338.00,A,3648.16832,N,12147.27475,W,0.253,0.00,180325,,,A*7C
2025-03-18T17:23:38.959Z,1742318618.959 [NAL9602](INFO): GPS fix at 20250318T172338: (36.802805, -121.787913)
2025-03-18T17:23:38.971Z,1742318618.971 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:23:38.971Z,1742318618.971 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:23:46.652Z,1742318626.652 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0037.lzma
2025-03-18T17:23:47.654Z,1742318627.654 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0037.lzma.bak
2025-03-18T17:23:47.654Z,1742318627.654 [DataOverHttps](INFO): SBD MOMSN=24371574
2025-03-18T17:24:03.492Z,1742318643.492 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20250318T161156/Express0038.lzma
2025-03-18T17:24:04.494Z,1742318644.494 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0038.lzma.bak
2025-03-18T17:24:04.494Z,1742318644.494 [DataOverHttps](INFO): SBD MOMSN=24371577
2025-03-18T17:24:06.034Z,1742318646.034 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:24:06.034Z,1742318646.034 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:24:06.034Z,1742318646.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:24:11.665Z,1742318651.665 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T17:27:16.337Z,1742318836.337 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T17:27:16.337Z,1742318836.337 [BPC1] No Fault, FailCount= 5
2025-03-18T17:29:06.606Z,1742318946.606 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:29:06.606Z,1742318946.606 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:29:06.606Z,1742318946.606 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:29:06.606Z,1742318946.606 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:29:07.016Z,1742318947.016 [Default:CheckIn:D] Stopped
2025-03-18T17:29:07.016Z,1742318947.016 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:29:07.404Z,1742318947.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.706226 min
2025-03-18T17:29:07.404Z,1742318947.404 [Default:CheckIn:E] Stopped
2025-03-18T17:29:07.404Z,1742318947.404 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:29:07.404Z,1742318947.404 [Default:CheckIn] Stopped
2025-03-18T17:29:07.404Z,1742318947.404 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:29:07.405Z,1742318947.405 [Default:CheckIn](INFO): Running loop #12
2025-03-18T17:29:07.405Z,1742318947.405 [Default:CheckIn] Running Loop=12
2025-03-18T17:29:07.405Z,1742318947.405 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:29:07.405Z,1742318947.405 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:29:09.419Z,1742318949.419 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172908.00,A,3648.16639,N,12147.27140,W,0.117,142.91,180325,,,A*7F
2025-03-18T17:29:09.422Z,1742318949.422 [NAL9602](INFO): GPS fix at 20250318T172908: (36.802773, -121.787857)
2025-03-18T17:29:09.433Z,1742318949.433 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:29:09.433Z,1742318949.433 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:29:16.352Z,1742318956.352 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250318T161156/Courier0040.lzma
2025-03-18T17:29:17.354Z,1742318957.354 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0040.lzma.bak
2025-03-18T17:29:17.354Z,1742318957.354 [DataOverHttps](INFO): SBD MOMSN=24371587
2025-03-18T17:29:33.280Z,1742318973.280 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20250318T161156/Express0041.lzma
2025-03-18T17:29:34.282Z,1742318974.282 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0041.lzma.bak
2025-03-18T17:29:34.282Z,1742318974.282 [DataOverHttps](INFO): SBD MOMSN=24371590
2025-03-18T17:29:35.696Z,1742318975.696 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:29:35.696Z,1742318975.696 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:29:35.697Z,1742318975.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:29:40.122Z,1742318980.122 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-18T17:29:40.204Z,1742318980.204 [NAL9602](ERROR): received:
+CSQ:0
OK217, 2, 0, 0, 0
OK
2025-03-18T17:31:17.096Z,1742319077.096 [NAL9602](INFO): SBD MO Status=2, MOMSN=22217, MT Status=2, MTMSN=0
2025-03-18T17:31:17.097Z,1742319077.097 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-03-18T17:32:16.872Z,1742319136.872 [BPC1](FAULT): Failed to initialize
2025-03-18T17:32:16.872Z,1742319136.872 [BPC1] Communications Fault, FailCount= 6
2025-03-18T17:32:16.873Z,1742319136.873 [BPC1](ERROR): Communications Fault
2025-03-18T17:32:16.937Z,1742319136.937 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T17:34:11.202Z,1742319251.202 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T17:34:36.262Z,1742319276.262 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:34:36.262Z,1742319276.262 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:34:36.262Z,1742319276.262 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:34:36.263Z,1742319276.263 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:34:36.675Z,1742319276.675 [Default:CheckIn:D] Stopped
2025-03-18T17:34:36.675Z,1742319276.675 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.200814 min
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn:E] Stopped
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn] Stopped
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn](INFO): Running loop #13
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn] Running Loop=13
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:34:37.097Z,1742319277.097 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:34:39.079Z,1742319279.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173438.00,A,3648.17764,N,12147.28320,W,0.991,138.79,180325,,,A*7E
2025-03-18T17:34:39.082Z,1742319279.082 [NAL9602](INFO): GPS fix at 20250318T173438: (36.802961, -121.788053)
2025-03-18T17:34:39.093Z,1742319279.093 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:34:39.093Z,1742319279.093 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:34:46.056Z,1742319286.056 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0043.lzma
2025-03-18T17:34:47.059Z,1742319287.059 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0043.lzma.bak
2025-03-18T17:34:47.059Z,1742319287.059 [DataOverHttps](INFO): SBD MOMSN=24371599
2025-03-18T17:35:02.684Z,1742319302.684 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20250318T161156/Express0044.lzma
2025-03-18T17:35:03.686Z,1742319303.686 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0044.lzma.bak
2025-03-18T17:35:03.686Z,1742319303.686 [DataOverHttps](INFO): SBD MOMSN=24371602
2025-03-18T17:35:04.962Z,1742319304.962 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:35:04.962Z,1742319304.962 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:35:04.962Z,1742319304.962 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:35:11.397Z,1742319311.397 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T17:40:05.520Z,1742319605.520 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:40:05.521Z,1742319605.521 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:40:05.521Z,1742319605.521 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:40:05.521Z,1742319605.521 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:40:05.926Z,1742319605.926 [Default:CheckIn:D] Stopped
2025-03-18T17:40:05.927Z,1742319605.927 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:40:06.340Z,1742319606.340 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.688330 min
2025-03-18T17:40:06.340Z,1742319606.340 [Default:CheckIn:E] Stopped
2025-03-18T17:40:06.340Z,1742319606.340 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:40:06.340Z,1742319606.340 [Default:CheckIn] Stopped
2025-03-18T17:40:06.340Z,1742319606.340 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:40:06.341Z,1742319606.341 [Default:CheckIn](INFO): Running loop #14
2025-03-18T17:40:06.341Z,1742319606.341 [Default:CheckIn] Running Loop=14
2025-03-18T17:40:06.341Z,1742319606.341 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:40:06.341Z,1742319606.341 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:40:08.343Z,1742319608.343 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174007.00,A,3648.17069,N,12147.27641,W,0.505,131.70,180325,,,A*77
2025-03-18T17:40:08.345Z,1742319608.345 [NAL9602](INFO): GPS fix at 20250318T174007: (36.802845, -121.787940)
2025-03-18T17:40:08.377Z,1742319608.377 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:40:08.377Z,1742319608.377 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:40:16.056Z,1742319616.056 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0046.lzma
2025-03-18T17:40:17.058Z,1742319617.058 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0046.lzma.bak
2025-03-18T17:40:17.058Z,1742319617.058 [DataOverHttps](INFO): SBD MOMSN=24371613
2025-03-18T17:40:32.856Z,1742319632.856 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20250318T161156/Express0047.lzma
2025-03-18T17:40:33.858Z,1742319633.858 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0047.lzma.bak
2025-03-18T17:40:33.858Z,1742319633.858 [DataOverHttps](INFO): SBD MOMSN=24371616
2025-03-18T17:40:35.429Z,1742319635.429 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:40:35.429Z,1742319635.429 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:40:35.429Z,1742319635.429 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:40:39.042Z,1742319639.042 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-18T17:40:39.120Z,1742319639.120 [NAL9602](ERROR): received:
+CSQ:0
OK217, 2, 0, 0, 0
OK
2025-03-18T17:42:11.969Z,1742319731.969 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-03-18T17:42:11.969Z,1742319731.969 [DropWeight] Hardware Fault, FailCount= 1
2025-03-18T17:42:11.969Z,1742319731.969 [DropWeight](ERROR): Hardware Fault
2025-03-18T17:42:12.032Z,1742319732.032 [CBIT](INFO): Critical error at 20250318T174211
2025-03-18T17:42:12.035Z,1742319732.035 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-03-18T17:42:12.035Z,1742319732.035 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-03-18T17:42:12.437Z,1742319732.437 [CBIT](INFO): Critical error at 20250318T174212
2025-03-18T17:42:18.066Z,1742319738.066 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T17:42:18.066Z,1742319738.066 [BPC1] No Fault, FailCount= 6
2025-03-18T17:45:10.561Z,1742319910.561 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T17:45:36.039Z,1742319936.039 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:45:36.039Z,1742319936.039 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:45:36.040Z,1742319936.040 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:45:36.040Z,1742319936.040 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:45:36.425Z,1742319936.425 [Default:CheckIn:D] Stopped
2025-03-18T17:45:36.425Z,1742319936.425 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:45:36.832Z,1742319936.832 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.196639 min
2025-03-18T17:45:36.832Z,1742319936.832 [Default:CheckIn:E] Stopped
2025-03-18T17:45:36.832Z,1742319936.832 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:45:36.832Z,1742319936.832 [Default:CheckIn] Stopped
2025-03-18T17:45:36.832Z,1742319936.832 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:45:36.832Z,1742319936.832 [Default:CheckIn](INFO): Running loop #15
2025-03-18T17:45:36.833Z,1742319936.833 [Default:CheckIn] Running Loop=15
2025-03-18T17:45:36.833Z,1742319936.833 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:45:36.833Z,1742319936.833 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:45:38.837Z,1742319938.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174538.00,A,3648.16565,N,12147.27606,W,0.408,131.70,180325,,,A*79
2025-03-18T17:45:38.839Z,1742319938.839 [NAL9602](INFO): GPS fix at 20250318T174538: (36.802761, -121.787934)
2025-03-18T17:45:38.850Z,1742319938.850 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:45:38.850Z,1742319938.850 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:45:46.524Z,1742319946.524 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250318T161156/Courier0049.lzma
2025-03-18T17:45:47.526Z,1742319947.526 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0049.lzma.bak
2025-03-18T17:45:47.526Z,1742319947.526 [DataOverHttps](INFO): SBD MOMSN=24371625
2025-03-18T17:46:03.244Z,1742319963.244 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20250318T161156/Express0050.lzma
2025-03-18T17:46:04.246Z,1742319964.246 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0050.lzma.bak
2025-03-18T17:46:04.246Z,1742319964.246 [DataOverHttps](INFO): SBD MOMSN=24371630
2025-03-18T17:46:05.519Z,1742319965.519 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:46:05.520Z,1742319965.520 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:46:05.520Z,1742319965.520 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:46:11.557Z,1742319971.557 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T17:47:18.623Z,1742320038.623 [BPC1](FAULT): Failed to initialize
2025-03-18T17:47:18.623Z,1742320038.623 [BPC1] Communications Fault, FailCount= 7
2025-03-18T17:47:18.623Z,1742320038.623 [BPC1](ERROR): Communications Fault
2025-03-18T17:47:18.645Z,1742320038.645 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T17:51:06.096Z,1742320266.096 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:51:06.096Z,1742320266.096 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:51:06.097Z,1742320266.097 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:51:06.097Z,1742320266.097 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:51:06.503Z,1742320266.503 [Default:CheckIn:D] Stopped
2025-03-18T17:51:06.503Z,1742320266.503 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:51:06.892Z,1742320266.892 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.697941 min
2025-03-18T17:51:06.892Z,1742320266.892 [Default:CheckIn:E] Stopped
2025-03-18T17:51:06.892Z,1742320266.892 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:51:06.892Z,1742320266.892 [Default:CheckIn] Stopped
2025-03-18T17:51:06.892Z,1742320266.892 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:51:06.893Z,1742320266.893 [Default:CheckIn](INFO): Running loop #16
2025-03-18T17:51:06.893Z,1742320266.893 [Default:CheckIn] Running Loop=16
2025-03-18T17:51:06.893Z,1742320266.893 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:51:06.893Z,1742320266.893 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:51:08.907Z,1742320268.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175108.00,A,3648.17567,N,12147.29120,W,1.050,284.99,180325,,,A*73
2025-03-18T17:51:08.909Z,1742320268.909 [NAL9602](INFO): GPS fix at 20250318T175108: (36.802928, -121.788187)
2025-03-18T17:51:08.925Z,1742320268.925 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:51:08.925Z,1742320268.925 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:51:16.652Z,1742320276.652 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20250318T161156/Courier0052.lzma
2025-03-18T17:51:17.654Z,1742320277.654 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0052.lzma.bak
2025-03-18T17:51:17.654Z,1742320277.654 [DataOverHttps](INFO): SBD MOMSN=24371640
2025-03-18T17:51:37.544Z,1742320297.544 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20250318T161156/Express0053.lzma
2025-03-18T17:51:38.546Z,1742320298.546 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0053.lzma.bak
2025-03-18T17:51:38.546Z,1742320298.546 [DataOverHttps](INFO): SBD MOMSN=24371643
2025-03-18T17:51:39.649Z,1742320299.649 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-18T17:51:39.732Z,1742320299.732 [NAL9602](ERROR): received:
+CSQ:0
OK217, 2, 0, 0, 0
OK
2025-03-18T17:51:40.097Z,1742320300.097 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:51:40.097Z,1742320300.097 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:51:40.097Z,1742320300.097 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:56:11.545Z,1742320571.545 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T17:56:40.669Z,1742320600.669 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T17:56:40.669Z,1742320600.669 [Default:CheckIn:C.Wait] Stopped
2025-03-18T17:56:40.669Z,1742320600.669 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T17:56:40.669Z,1742320600.669 [Default:CheckIn:D] Running Loop=1
2025-03-18T17:56:41.047Z,1742320601.047 [Default:CheckIn:D] Stopped
2025-03-18T17:56:41.047Z,1742320601.047 [Default:CheckIn:E] Running Loop=1
2025-03-18T17:56:41.465Z,1742320601.465 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.273682 min
2025-03-18T17:56:41.465Z,1742320601.465 [Default:CheckIn:E] Stopped
2025-03-18T17:56:41.466Z,1742320601.466 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T17:56:41.466Z,1742320601.466 [Default:CheckIn] Stopped
2025-03-18T17:56:41.466Z,1742320601.466 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T17:56:41.466Z,1742320601.466 [Default:CheckIn](INFO): Running loop #17
2025-03-18T17:56:41.466Z,1742320601.466 [Default:CheckIn] Running Loop=17
2025-03-18T17:56:41.466Z,1742320601.466 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T17:56:41.466Z,1742320601.466 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T17:56:43.467Z,1742320603.467 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175642.00,A,3648.17410,N,12147.27440,W,0.544,148.95,180325,,,A*78
2025-03-18T17:56:43.480Z,1742320603.480 [NAL9602](INFO): GPS fix at 20250318T175642: (36.802902, -121.787907)
2025-03-18T17:56:43.491Z,1742320603.491 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T17:56:43.492Z,1742320603.492 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T17:56:51.436Z,1742320611.436 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0055.lzma
2025-03-18T17:56:52.438Z,1742320612.438 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0055.lzma.bak
2025-03-18T17:56:52.438Z,1742320612.438 [DataOverHttps](INFO): SBD MOMSN=24371732
2025-03-18T17:57:08.096Z,1742320628.096 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20250318T161156/Express0056.lzma
2025-03-18T17:57:09.098Z,1742320629.098 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0056.lzma.bak
2025-03-18T17:57:09.098Z,1742320629.098 [DataOverHttps](INFO): SBD MOMSN=24371735
2025-03-18T17:57:10.539Z,1742320630.539 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T17:57:10.539Z,1742320630.539 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T17:57:10.539Z,1742320630.539 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T17:57:12.218Z,1742320632.218 [CBIT](INFO): Clearing failed state for component DropWeight
2025-03-18T17:57:12.218Z,1742320632.218 [DropWeight] No Fault, FailCount= 1
2025-03-18T17:57:15.382Z,1742320635.382 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T17:57:19.844Z,1742320639.844 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T17:57:19.844Z,1742320639.844 [BPC1] No Fault, FailCount= 7
2025-03-18T18:02:11.125Z,1742320931.125 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T18:02:11.125Z,1742320931.125 [Default:CheckIn:C.Wait] Stopped
2025-03-18T18:02:11.125Z,1742320931.125 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T18:02:11.126Z,1742320931.126 [Default:CheckIn:D] Running Loop=1
2025-03-18T18:02:11.520Z,1742320931.520 [Default:CheckIn:D] Stopped
2025-03-18T18:02:11.520Z,1742320931.520 [Default:CheckIn:E] Running Loop=1
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.781559 min
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn:E] Stopped
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn] Stopped
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn](INFO): Running loop #18
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn] Running Loop=18
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T18:02:11.929Z,1742320931.929 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T18:02:13.937Z,1742320933.937 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180213.00,A,3648.17015,N,12147.27528,W,0.525,191.06,180325,,,A*75
2025-03-18T18:02:13.939Z,1742320933.939 [NAL9602](INFO): GPS fix at 20250318T180213: (36.802836, -121.787921)
2025-03-18T18:02:13.950Z,1742320933.950 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T18:02:13.950Z,1742320933.950 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T18:02:20.398Z,1742320940.398 [BPC1](FAULT): Failed to initialize
2025-03-18T18:02:20.398Z,1742320940.398 [BPC1] Communications Fault, FailCount= 8
2025-03-18T18:02:20.398Z,1742320940.398 [BPC1](ERROR): Communications Fault
2025-03-18T18:02:20.425Z,1742320940.425 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T18:02:20.872Z,1742320940.872 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0058.lzma
2025-03-18T18:02:21.874Z,1742320941.874 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0058.lzma.bak
2025-03-18T18:02:21.874Z,1742320941.874 [DataOverHttps](INFO): SBD MOMSN=24371745
2025-03-18T18:02:37.640Z,1742320957.640 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20250318T161156/Express0059.lzma
2025-03-18T18:02:38.642Z,1742320958.642 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0059.lzma.bak
2025-03-18T18:02:38.642Z,1742320958.642 [DataOverHttps](INFO): SBD MOMSN=24371748
2025-03-18T18:02:40.210Z,1742320960.210 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T18:02:40.210Z,1742320960.210 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T18:02:40.211Z,1742320960.211 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T18:02:44.641Z,1742320964.641 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-18T18:02:44.724Z,1742320964.724 [NAL9602](ERROR): received:
+CSQ:0
OK217, 2, 0, 0, 0
OK
2025-03-18T18:07:16.529Z,1742321236.529 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T18:07:40.791Z,1742321260.791 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T18:07:40.791Z,1742321260.791 [Default:CheckIn:C.Wait] Stopped
2025-03-18T18:07:40.791Z,1742321260.791 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T18:07:40.791Z,1742321260.791 [Default:CheckIn:D] Running Loop=1
2025-03-18T18:07:41.187Z,1742321261.187 [Default:CheckIn:D] Stopped
2025-03-18T18:07:41.187Z,1742321261.187 [Default:CheckIn:E] Running Loop=1
2025-03-18T18:07:41.592Z,1742321261.592 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.276009 min
2025-03-18T18:07:41.592Z,1742321261.592 [Default:CheckIn:E] Stopped
2025-03-18T18:07:41.592Z,1742321261.592 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T18:07:41.592Z,1742321261.592 [Default:CheckIn] Stopped
2025-03-18T18:07:41.593Z,1742321261.593 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T18:07:41.593Z,1742321261.593 [Default:CheckIn](INFO): Running loop #19
2025-03-18T18:07:41.593Z,1742321261.593 [Default:CheckIn] Running Loop=19
2025-03-18T18:07:41.593Z,1742321261.593 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T18:07:41.593Z,1742321261.593 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T18:07:43.601Z,1742321263.601 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180742.00,A,3648.17725,N,12147.28295,W,1.400,191.06,180325,,,A*79
2025-03-18T18:07:43.603Z,1742321263.603 [NAL9602](INFO): GPS fix at 20250318T180742: (36.802954, -121.788049)
2025-03-18T18:07:43.615Z,1742321263.615 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T18:07:43.615Z,1742321263.615 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T18:07:51.112Z,1742321271.112 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250318T161156/Courier0061.lzma
2025-03-18T18:07:52.114Z,1742321272.114 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0061.lzma.bak
2025-03-18T18:07:52.114Z,1742321272.114 [DataOverHttps](INFO): SBD MOMSN=24371786
2025-03-18T18:08:07.792Z,1742321287.792 [DataOverHttps](INFO): Sending 263 bytes from file Logs/20250318T161156/Express0062.lzma
2025-03-18T18:08:08.794Z,1742321288.794 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0062.lzma.bak
2025-03-18T18:08:08.794Z,1742321288.794 [DataOverHttps](INFO): SBD MOMSN=24371789
2025-03-18T18:08:10.280Z,1742321290.280 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T18:08:10.281Z,1742321290.281 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T18:08:10.281Z,1742321290.281 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T18:08:16.321Z,1742321296.321 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-18T18:12:09.098Z,1742321529.098 [CBIT](FAULT): Main Battery Failure
2025-03-18T18:12:21.615Z,1742321541.615 [CBIT](INFO): Clearing failed state for component BPC1
2025-03-18T18:12:21.616Z,1742321541.616 [BPC1] No Fault, FailCount= 8
2025-03-18T18:13:10.903Z,1742321590.903 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T18:13:10.903Z,1742321590.903 [Default:CheckIn:C.Wait] Stopped
2025-03-18T18:13:10.903Z,1742321590.903 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T18:13:10.903Z,1742321590.903 [Default:CheckIn:D] Running Loop=1
2025-03-18T18:13:11.296Z,1742321591.296 [Default:CheckIn:D] Stopped
2025-03-18T18:13:11.296Z,1742321591.296 [Default:CheckIn:E] Running Loop=1
2025-03-18T18:13:11.704Z,1742321591.704 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.777816 min
2025-03-18T18:13:11.704Z,1742321591.704 [Default:CheckIn:E] Stopped
2025-03-18T18:13:11.704Z,1742321591.704 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T18:13:11.705Z,1742321591.705 [Default:CheckIn] Stopped
2025-03-18T18:13:11.705Z,1742321591.705 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T18:13:11.705Z,1742321591.705 [Default:CheckIn](INFO): Running loop #20
2025-03-18T18:13:11.705Z,1742321591.705 [Default:CheckIn] Running Loop=20
2025-03-18T18:13:11.705Z,1742321591.705 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T18:13:11.705Z,1742321591.705 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T18:13:13.721Z,1742321593.721 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181313.00,A,3648.17537,N,12147.27801,W,0.097,268.17,180325,,,A*7F
2025-03-18T18:13:13.724Z,1742321593.724 [NAL9602](INFO): GPS fix at 20250318T181313: (36.802923, -121.787967)
2025-03-18T18:13:13.735Z,1742321593.735 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T18:13:13.735Z,1742321593.735 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T18:13:20.744Z,1742321600.744 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0064.lzma
2025-03-18T18:13:21.746Z,1742321601.746 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0064.lzma.bak
2025-03-18T18:13:21.747Z,1742321601.747 [DataOverHttps](INFO): SBD MOMSN=24371800
2025-03-18T18:13:41.080Z,1742321621.080 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20250318T161156/Express0065.lzma
2025-03-18T18:13:42.082Z,1742321622.082 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0065.lzma.bak
2025-03-18T18:13:42.082Z,1742321622.082 [DataOverHttps](INFO): SBD MOMSN=24371803
2025-03-18T18:13:43.621Z,1742321623.621 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T18:13:43.621Z,1742321623.621 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T18:13:43.621Z,1742321623.621 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T18:13:44.415Z,1742321624.415 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-18T18:13:44.496Z,1742321624.496 [NAL9602](ERROR): received:
+CSQ:0
OK217, 2, 0, 0, 0
OK
2025-03-18T18:17:22.168Z,1742321842.168 [BPC1](FAULT): Failed to initialize
2025-03-18T18:17:22.168Z,1742321842.168 [BPC1] Communications Fault, FailCount= 9
2025-03-18T18:17:22.168Z,1742321842.168 [BPC1](ERROR): Communications Fault
2025-03-18T18:17:22.245Z,1742321842.245 [CBIT](ERROR): Communications Fault in component: BPC1
2025-03-18T18:18:16.310Z,1742321896.310 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-18T18:18:44.195Z,1742321924.195 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-18T18:18:44.195Z,1742321924.195 [Default:CheckIn:C.Wait] Stopped
2025-03-18T18:18:44.195Z,1742321924.195 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-18T18:18:44.196Z,1742321924.196 [Default:CheckIn:D] Running Loop=1
2025-03-18T18:18:44.599Z,1742321924.599 [Default:CheckIn:D] Stopped
2025-03-18T18:18:44.599Z,1742321924.599 [Default:CheckIn:E] Running Loop=1
2025-03-18T18:18:45.009Z,1742321925.009 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.332869 min
2025-03-18T18:18:45.009Z,1742321925.009 [Default:CheckIn:E] Stopped
2025-03-18T18:18:45.009Z,1742321925.009 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-18T18:18:45.009Z,1742321925.009 [Default:CheckIn] Stopped
2025-03-18T18:18:45.009Z,1742321925.009 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-18T18:18:45.009Z,1742321925.009 [Default:CheckIn](INFO): Running loop #21
2025-03-18T18:18:45.010Z,1742321925.010 [Default:CheckIn] Running Loop=21
2025-03-18T18:18:45.010Z,1742321925.010 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-18T18:18:45.010Z,1742321925.010 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-18T18:18:47.015Z,1742321927.015 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181846.00,A,3648.17580,N,12147.28022,W,0.758,194.81,180325,,,A*75
2025-03-18T18:18:47.017Z,1742321927.017 [NAL9602](INFO): GPS fix at 20250318T181846: (36.802930, -121.788004)
2025-03-18T18:18:47.045Z,1742321927.045 [Default:CheckIn:Read_GPS] Stopped
2025-03-18T18:18:47.045Z,1742321927.045 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-18T18:18:54.960Z,1742321934.960 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250318T161156/Courier0067.lzma
2025-03-18T18:18:55.962Z,1742321935.962 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Courier0067.lzma.bak
2025-03-18T18:18:55.962Z,1742321935.962 [DataOverHttps](INFO): SBD MOMSN=24371840
2025-03-18T18:19:11.642Z,1742321951.642 [DataOverHttps](INFO): Sending 263 bytes from file Logs/20250318T161156/Express0068.lzma
2025-03-18T18:19:12.638Z,1742321952.638 [DataOverHttps](INFO): Moved sent file to Logs/20250318T161156/Express0068.lzma.bak
2025-03-18T18:19:12.638Z,1742321952.638 [DataOverHttps](INFO): SBD MOMSN=24371843
2025-03-18T18:19:14.103Z,1742321954.103 [Default:CheckIn:Read_Iridium] Stopped
2025-03-18T18:19:14.103Z,1742321954.103 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-18T18:19:14.103Z,1742321954.103 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-18T18:19:19.342Z,