2025-06-18T17:27:31.593Z,1750267651.593 [Supervisor](DEBUG): Initializing supervisor.
2025-06-18T17:27:31.598Z,1750267651.598 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-06-18T17:27:31.599Z,1750267651.599 [SyncHandler](INFO): Protected caller Thread ID is 9836
2025-06-18T17:27:31.599Z,1750267651.599 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-06-18T17:27:31.600Z,1750267651.600 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-06-18T17:27:31.601Z,1750267651.601 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9837
2025-06-18T17:27:31.605Z,1750267651.605 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-06-18T17:27:31.625Z,1750267651.625 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-06-18T17:27:31.626Z,1750267651.626 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-06-18T17:27:31.626Z,1750267651.626 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 9838
2025-06-18T17:27:31.631Z,1750267651.631 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-06-18T17:27:31.632Z,1750267651.632 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-06-18T17:27:31.632Z,1750267651.632 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9839
2025-06-18T17:27:31.634Z,1750267651.634 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-06-18T17:27:31.635Z,1750267651.635 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-06-18T17:27:31.636Z,1750267651.636 [logger ThreadHandler](INFO): Protected caller Thread ID is 9840
2025-06-18T17:27:31.639Z,1750267651.639 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-06-18T17:27:31.640Z,1750267651.640 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-06-18T17:27:31.641Z,1750267651.641 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-06-18T17:27:31.747Z,1750267651.747 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-06-18T17:27:31.747Z,1750267651.747 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-06-18T17:27:31.977Z,1750267651.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-06-18T17:27:31.978Z,1750267651.978 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-06-18T17:27:32.247Z,1750267652.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-06-18T17:27:32.247Z,1750267652.247 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-06-18T17:27:32.363Z,1750267652.363 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-06-18T17:27:32.364Z,1750267652.364 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-06-18T17:27:33.218Z,1750267653.218 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-06-18T17:27:33.218Z,1750267653.218 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-06-18T17:27:33.733Z,1750267653.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-06-18T17:27:33.734Z,1750267653.734 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-06-18T17:27:34.282Z,1750267654.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-06-18T17:27:34.283Z,1750267654.283 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-06-18T17:27:34.704Z,1750267654.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-06-18T17:27:34.704Z,1750267654.704 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-06-18T17:27:35.062Z,1750267655.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-06-18T17:27:35.063Z,1750267655.063 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-06-18T17:27:35.448Z,1750267655.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-06-18T17:27:35.448Z,1750267655.448 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-06-18T17:27:35.691Z,1750267655.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-06-18T17:27:35.692Z,1750267655.692 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-06-18T17:27:35.843Z,1750267655.843 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-06-18T17:27:35.844Z,1750267655.844 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-06-18T17:27:35.947Z,1750267655.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-06-18T17:27:35.947Z,1750267655.947 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-06-18T17:27:36.038Z,1750267656.038 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-06-18T17:27:36.233Z,1750267656.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-06-18T17:27:36.233Z,1750267656.233 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-06-18T17:27:36.489Z,1750267656.489 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-06-18T17:27:36.491Z,1750267656.491 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-06-18T17:27:36.491Z,1750267656.491 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-06-18T17:27:36.585Z,1750267656.585 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-06-18T17:27:36.860Z,1750267656.860 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-06-18T17:27:36.860Z,1750267656.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-06-18T17:27:36.955Z,1750267656.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-06-18T17:27:37.135Z,1750267657.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-06-18T17:27:37.246Z,1750267657.246 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-06-18T17:27:37.367Z,1750267657.367 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-06-18T17:27:37.490Z,1750267657.490 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-06-18T17:27:37.595Z,1750267657.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-06-18T17:27:37.766Z,1750267657.766 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-06-18T17:27:37.874Z,1750267657.874 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-06-18T17:27:37.969Z,1750267657.969 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-06-18T17:27:38.078Z,1750267658.078 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-06-18T17:27:38.177Z,1750267658.177 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2025-06-18T17:27:38.177Z,1750267658.177 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-06-18T17:27:38.183Z,1750267658.183 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-06-18T17:27:38.367Z,1750267658.367 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-06-18T17:27:38.368Z,1750267658.368 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-06-18T17:27:38.714Z,1750267658.714 [BuoyancyServo] Loaded
2025-06-18T17:27:38.714Z,1750267658.714 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-06-18T17:27:38.745Z,1750267658.745 [ElevatorServo] Loaded
2025-06-18T17:27:38.745Z,1750267658.745 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-06-18T17:27:38.767Z,1750267658.767 [MassServo] Loaded
2025-06-18T17:27:38.767Z,1750267658.767 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-06-18T17:27:38.789Z,1750267658.789 [RudderServo] Loaded
2025-06-18T17:27:38.789Z,1750267658.789 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-06-18T17:27:38.807Z,1750267658.807 [ThrusterHE] Loaded
2025-06-18T17:27:38.807Z,1750267658.807 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-06-18T17:27:38.808Z,1750267658.808 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-06-18T17:27:38.808Z,1750267658.808 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-06-18T17:27:39.193Z,1750267659.193 [SBIT](DEBUG): Construct Startup Built In Test.
2025-06-18T17:27:39.208Z,1750267659.208 [SBIT] Loaded
2025-06-18T17:27:39.208Z,1750267659.208 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-06-18T17:27:39.211Z,1750267659.211 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-06-18T17:27:39.231Z,1750267659.231 [IBIT] Loaded
2025-06-18T17:27:39.232Z,1750267659.232 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-06-18T17:27:39.237Z,1750267659.237 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-06-18T17:27:39.429Z,1750267659.429 [CBIT] Loaded
2025-06-18T17:27:39.430Z,1750267659.430 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-06-18T17:27:39.460Z,1750267659.460 [GFScanner] Loaded
2025-06-18T17:27:39.460Z,1750267659.460 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-06-18T17:27:39.461Z,1750267659.461 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-06-18T17:27:39.461Z,1750267659.461 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-06-18T17:27:39.631Z,1750267659.631 [CTD_Seabird] Loaded
2025-06-18T17:27:39.632Z,1750267659.632 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-06-18T17:27:39.633Z,1750267659.633 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406864E0
2025-06-18T17:27:39.633Z,1750267659.633 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9928
2025-06-18T17:27:39.667Z,1750267659.667 [ESPComponent] Loaded
2025-06-18T17:27:39.668Z,1750267659.668 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-06-18T17:27:39.689Z,1750267659.689 [PAR_Licor] Loaded
2025-06-18T17:27:39.690Z,1750267659.690 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-06-18T17:27:39.734Z,1750267659.734 [WetLabsBB2FL] Loaded
2025-06-18T17:27:39.735Z,1750267659.735 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-06-18T17:27:39.736Z,1750267659.736 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0
2025-06-18T17:27:39.736Z,1750267659.736 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9929
2025-06-18T17:27:39.737Z,1750267659.737 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-06-18T17:27:39.737Z,1750267659.737 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-06-18T17:27:39.789Z,1750267659.789 [DepthRateCalculator] Loaded
2025-06-18T17:27:39.790Z,1750267659.790 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-06-18T17:27:39.795Z,1750267659.795 [PitchRateCalculator] Loaded
2025-06-18T17:27:39.795Z,1750267659.795 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-06-18T17:27:39.805Z,1750267659.805 [SpeedCalculator] Loaded
2025-06-18T17:27:39.806Z,1750267659.806 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-06-18T17:27:39.810Z,1750267659.810 [YawRateCalculator] Loaded
2025-06-18T17:27:39.810Z,1750267659.810 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-06-18T17:27:39.830Z,1750267659.830 [ElevatorOffsetCalculator] Loaded
2025-06-18T17:27:39.830Z,1750267659.830 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-06-18T17:27:39.831Z,1750267659.831 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-06-18T17:27:39.831Z,1750267659.831 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-06-18T17:27:39.969Z,1750267659.969 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-06-18T17:27:39.970Z,1750267659.970 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-06-18T17:27:39.000Z,1750267660.000 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-06-18T17:27:40.000Z,1750267660.000 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-06-18T17:27:40.114Z,1750267660.114 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-06-18T17:27:40.115Z,1750267660.115 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-06-18T17:27:40.128Z,1750267660.128 [NavChart] Loaded
2025-06-18T17:27:40.129Z,1750267660.129 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-06-18T17:27:40.134Z,1750267660.134 [UniversalFixResidualReporter] Loaded
2025-06-18T17:27:40.135Z,1750267660.135 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-06-18T17:27:40.135Z,1750267660.135 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-06-18T17:27:40.136Z,1750267660.136 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-06-18T17:27:40.624Z,1750267660.624 [AHRS_M2] Loaded
2025-06-18T17:27:40.624Z,1750267660.624 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-06-18T17:27:40.663Z,1750267660.663 [BackseatComponent] Loaded
2025-06-18T17:27:40.663Z,1750267660.663 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-06-18T17:27:40.664Z,1750267660.664 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A824E0
2025-06-18T17:27:40.665Z,1750267660.665 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9930
2025-06-18T17:27:40.667Z,1750267660.667 [LcmUniversalReporter] Loaded
2025-06-18T17:27:40.668Z,1750267660.668 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-06-18T17:27:41.407Z,1750267661.407 [BPC1] Loaded
2025-06-18T17:27:41.407Z,1750267661.407 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-06-18T17:27:41.507Z,1750267661.507 [DAT] Loaded
2025-06-18T17:27:41.508Z,1750267661.508 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-06-18T17:27:41.509Z,1750267661.509 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB24E0
2025-06-18T17:27:41.509Z,1750267661.509 [DAT ThreadHandler](INFO): Protected caller Thread ID is 9931
2025-06-18T17:27:41.582Z,1750267661.582 [DataOverHttps] Loaded
2025-06-18T17:27:41.582Z,1750267661.582 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-06-18T17:27:41.583Z,1750267661.583 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE24E0
2025-06-18T17:27:41.584Z,1750267661.584 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9932
2025-06-18T17:27:41.607Z,1750267661.607 [Depth_Keller] Loaded
2025-06-18T17:27:41.607Z,1750267661.607 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-06-18T17:27:41.613Z,1750267661.613 [DropWeight] Loaded
2025-06-18T17:27:41.613Z,1750267661.613 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-06-18T17:27:41.654Z,1750267661.654 [DVL_micro] Loaded
2025-06-18T17:27:41.654Z,1750267661.654 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2025-06-18T17:27:41.717Z,1750267661.717 [NAL9602] Loaded
2025-06-18T17:27:41.717Z,1750267661.717 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-06-18T17:27:41.743Z,1750267661.743 [Onboard] Loaded
2025-06-18T17:27:41.743Z,1750267661.743 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-06-18T17:27:41.744Z,1750267661.744 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B124E0
2025-06-18T17:27:41.745Z,1750267661.745 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9933
2025-06-18T17:27:41.751Z,1750267661.751 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2025-06-18T17:27:41.765Z,1750267661.765 [PowerOnly] Loaded
2025-06-18T17:27:41.765Z,1750267661.765 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-06-18T17:27:41.779Z,1750267661.779 [Power24vConverter] Loaded
2025-06-18T17:27:41.779Z,1750267661.779 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-06-18T17:27:41.796Z,1750267661.796 [Radio_Surface] Loaded
2025-06-18T17:27:41.796Z,1750267661.796 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-06-18T17:27:41.797Z,1750267661.797 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B424E0
2025-06-18T17:27:41.797Z,1750267661.797 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9934
2025-06-18T17:27:41.813Z,1750267661.813 [Sonardyne_Nano] Loaded
2025-06-18T17:27:41.813Z,1750267661.813 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-06-18T17:27:41.814Z,1750267661.814 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-06-18T17:27:41.814Z,1750267661.814 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-06-18T17:27:41.875Z,1750267661.875 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-06-18T17:27:41.876Z,1750267661.876 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-06-18T17:27:41.930Z,1750267661.930 [VerticalControl](DEBUG): Construct VerticalControl.
2025-06-18T17:27:41.982Z,1750267661.982 [VerticalControl] Loaded
2025-06-18T17:27:41.982Z,1750267661.982 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-06-18T17:27:41.985Z,1750267661.985 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-06-18T17:27:42.030Z,1750267662.030 [HorizontalControl] Loaded
2025-06-18T17:27:42.030Z,1750267662.030 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-06-18T17:27:42.032Z,1750267662.032 [SpeedControl](DEBUG): Construct SpeedControl.
2025-06-18T17:27:42.034Z,1750267662.034 [SpeedControl] Loaded
2025-06-18T17:27:42.034Z,1750267662.034 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-06-18T17:27:42.037Z,1750267662.037 [LoopControl](DEBUG): Construct LoopControl.
2025-06-18T17:27:42.038Z,1750267662.038 [LoopControl] Loaded
2025-06-18T17:27:42.038Z,1750267662.038 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-06-18T17:27:42.038Z,1750267662.038 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-06-18T17:27:42.039Z,1750267662.039 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-06-18T17:27:42.049Z,1750267662.049 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-06-18T17:27:42.050Z,1750267662.050 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-06-18T17:27:42.407Z,1750267662.407 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-06-18T17:27:42.413Z,1750267662.413 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-06-18T17:27:42.416Z,1750267662.416 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-06-18T17:27:42.427Z,1750267662.427 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-06-18T17:27:42.428Z,1750267662.428 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C684E0
2025-06-18T17:27:42.429Z,1750267662.429 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9935
2025-06-18T17:27:42.433Z,1750267662.433 [Supervisor](INFO): Main Thread ID is 9150
2025-06-18T17:27:42.433Z,1750267662.433 [Supervisor](DEBUG): Running supervisor.
2025-06-18T17:27:42.434Z,1750267662.434 [CommandExec ThreadHandler](INFO): Handler Thread ID is 9936
2025-06-18T17:27:42.434Z,1750267662.434 [CommandExec](INFO): Initializing the command executive.
2025-06-18T17:27:42.436Z,1750267662.436 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9937
2025-06-18T17:27:42.438Z,1750267662.438 [controlThread ThreadHandler](INFO): Handler Thread ID is 9938
2025-06-18T17:27:42.439Z,1750267662.439 [controlThread](DEBUG): Initializing ControlThread
2025-06-18T17:27:42.441Z,1750267662.441 [SBIT](INFO): Initialize SBIT Component.
2025-06-18T17:27:42.441Z,1750267662.441 [SBIT](IMPORTANT): git: 2025-05-29
2025-06-18T17:27:42.441Z,1750267662.441 [SBIT](INFO): git hash: c78c975c7bb2a66b27244d2837f68dff299fa024
2025-06-18T17:27:42.442Z,1750267662.442 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-06-18T17:27:42.443Z,1750267662.443 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-06-18T17:27:42.444Z,1750267662.444 [SBIT](INFO): Beginning SBIT in 151.000000 seconds.
2025-06-18T17:27:42.445Z,1750267662.445 [IBIT](INFO): Initialize IBIT Component.
2025-06-18T17:27:42.445Z,1750267662.445 [CBIT](DEBUG): Initialize CBIT Component.
2025-06-18T17:27:42.446Z,1750267662.446 [logger ThreadHandler](INFO): Handler Thread ID is 9939
2025-06-18T17:27:42.456Z,1750267662.456 [CBIT](DEBUG): Initialized mux pins.
2025-06-18T17:27:42.456Z,1750267662.456 [CBIT](DEBUG): Initializing the watchdog timer.
2025-06-18T17:27:42.465Z,1750267662.465 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9940
2025-06-18T17:27:42.465Z,1750267662.465 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-06-18T17:27:42.470Z,1750267662.470 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9942
2025-06-18T17:27:42.473Z,1750267662.473 [WetLabsBB2FL](INFO): Powering up
2025-06-18T17:27:42.474Z,1750267662.474 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9944
2025-06-18T17:27:42.480Z,1750267662.480 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-06-18T17:27:42.480Z,1750267662.480 [CBIT](DEBUG): Initializing heartbeat.
2025-06-18T17:27:42.482Z,1750267662.482 [DAT ThreadHandler](INFO): Handler Thread ID is 9945
2025-06-18T17:27:42.482Z,1750267662.482 [DAT](INFO): Powering up
2025-06-18T17:27:42.483Z,1750267662.483 [DAT](DEBUG): Initializing DAT.
2025-06-18T17:27:42.485Z,1750267662.485 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9947
2025-06-18T17:27:42.487Z,1750267662.487 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-06-18T17:27:42.497Z,1750267662.497 [Onboard ThreadHandler](INFO): Handler Thread ID is 9948
2025-06-18T17:27:42.514Z,1750267662.514 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9949
2025-06-18T17:27:42.532Z,1750267662.532 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9950
2025-06-18T17:27:42.539Z,1750267662.539 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-06-18T17:27:42.539Z,1750267662.539 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-06-18T17:27:42.539Z,1750267662.539 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-06-18T17:27:42.539Z,1750267662.539 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-06-18T17:27:42.539Z,1750267662.539 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-06-18T17:27:42.540Z,1750267662.540 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-06-18T17:27:42.540Z,1750267662.540 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-06-18T17:27:42.540Z,1750267662.540 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-06-18T17:27:42.552Z,1750267662.552 [CBIT](DEBUG): Deactivating emergency mode.
2025-06-18T17:27:42.592Z,1750267662.592 [CBIT](DEBUG): Backplane powered.
2025-06-18T17:27:42.592Z,1750267662.592 [GFScanner](DEBUG): Initializing GFScanner
2025-06-18T17:27:42.593Z,1750267662.593 [GFScanner](DEBUG): Deactivating GF circuits.
2025-06-18T17:27:42.600Z,1750267662.600 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-06-18T17:27:42.601Z,1750267662.601 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-06-18T17:27:42.601Z,1750267662.601 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-06-18T17:27:42.602Z,1750267662.602 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-06-18T17:27:42.602Z,1750267662.602 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-06-18T17:27:42.603Z,1750267662.603 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-06-18T17:27:42.603Z,1750267662.603 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-06-18T17:27:42.615Z,1750267662.615 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-06-18T17:27:42.625Z,1750267662.625 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-06-18T17:27:42.626Z,1750267662.626 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-06-18T17:27:42.626Z,1750267662.626 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-06-18T17:27:42.627Z,1750267662.627 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-06-18T17:27:42.628Z,1750267662.628 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-06-18T17:27:42.628Z,1750267662.628 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-06-18T17:27:42.637Z,1750267662.637 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-06-18T17:27:42.719Z,1750267662.719 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-06-18T17:27:42.748Z,1750267662.748 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-06-18T17:27:42.781Z,1750267662.781 [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-06-18T17:27:42.782Z,1750267662.782 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-06-18T17:27:42.782Z,1750267662.782 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-06-18T17:27:42.783Z,1750267662.783 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-06-18T17:27:42.920Z,1750267662.920 [Radio_Surface](INFO): Powering up
2025-06-18T17:27:43.108Z,1750267663.108 [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-06-18T17:27:43.130Z,1750267663.130 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-06-18T17:27:43.131Z,1750267663.131 [Default:A.Wait](DEBUG): Construct Wait.
2025-06-18T17:27:43.134Z,1750267663.134 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-06-18T17:27:43.175Z,1750267663.175 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-06-18T17:27:43.183Z,1750267663.183 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-06-18T17:27:43.205Z,1750267663.205 [Default:E.Execute](DEBUG): Construct Execute.
2025-06-18T17:27:43.208Z,1750267663.208 [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-06-18T17:27:43.229Z,1750267663.229 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,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-06-18T17:27:43.246Z,1750267663.246 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-06-18T17:27:43.305Z,1750267663.305 [Depth_Keller](INFO): Initializing.
2025-06-18T17:27:43.314Z,1750267663.314 [PowerOnly](INFO): Powering up loadControl
2025-06-18T17:27:43.333Z,1750267663.333 [Power24vConverter](INFO): Powering up.
2025-06-18T17:27:43.333Z,1750267663.333 [Sonardyne_Nano](INFO): Initializing.
2025-06-18T17:27:43.361Z,1750267663.361 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-06-18T17:27:43.384Z,1750267663.384 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-06-18T17:27:43.400Z,1750267663.400 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-06-18T17:27:43.401Z,1750267663.401 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-06-18T17:27:43.408Z,1750267663.408 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-06-18T17:27:43.409Z,1750267663.409 [MassServo](DEBUG): Initializing EZServoServo.
2025-06-18T17:27:43.416Z,1750267663.416 [MassServo](DEBUG): Initializing MassServo.
2025-06-18T17:27:43.417Z,1750267663.417 [RudderServo](DEBUG): Initializing EZServoServo.
2025-06-18T17:27:43.428Z,1750267663.428 [RudderServo](DEBUG): Initializing RudderServo.
2025-06-18T17:27:43.429Z,1750267663.429 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-06-18T17:27:43.436Z,1750267663.436 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-06-18T17:27:45.084Z,1750267665.084 [WetLabsBB2FL](INFO): Powering down
2025-06-18T17:27:45.268Z,1750267665.268 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-06-18T17:27:46.910Z,1750267666.910 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-06-18T17:27:49.497Z,1750267669.497 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-06-18T17:27:54.581Z,1750267674.581 [DAT](INFO): DAT read:
2025-06-18T17:27:54.582Z,1750267674.582 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-06-18T17:27:56.345Z,1750267676.345 [DAT](INFO): DAT read: MF Frequency Band
2025-06-18T17:27:56.346Z,1750267676.346 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-06-18T17:27:56.347Z,1750267676.347 [DAT](INFO): DAT read: Jun 18 2025 17:28:00
2025-06-18T17:27:57.606Z,1750267677.606 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-06-18T17:27:57.607Z,1750267677.607 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2025-06-18T17:27:57.607Z,1750267677.607 [DAT](INFO): commRate: 1200
2025-06-18T17:27:59.673Z,1750267679.673 [DAT](INFO): entering command mode
2025-06-18T17:27:59.873Z,1750267679.873 [DAT](INFO): DAT read:
2025-06-18T17:27:59.873Z,1750267679.873 [DAT](INFO): DAT read: user:1>
2025-06-18T17:27:59.874Z,1750267679.874 [DAT](INFO): setting verbose to 3
2025-06-18T17:28:00.125Z,1750267680.125 [DAT](INFO): DAT read: user:1>
2025-06-18T17:28:00.126Z,1750267680.126 [DAT](INFO): DAT read: Verbose | 3
2025-06-18T17:28:00.127Z,1750267680.127 [DAT](INFO): set verbose to 3
2025-06-18T17:28:00.127Z,1750267680.127 [DAT](INFO): setting DatVerbose to 27440
2025-06-18T17:28:00.377Z,1750267680.377 [DAT](INFO): DAT read: user:2>
2025-06-18T17:28:00.378Z,1750267680.378 [DAT](INFO): DAT read: DatVerbose | 27440
2025-06-18T17:28:00.378Z,1750267680.378 [DAT](INFO): set DatVerbose to 27440
2025-06-18T17:28:00.379Z,1750267680.379 [DAT](INFO): setting transmit power to 8
2025-06-18T17:28:00.629Z,1750267680.629 [DAT](INFO): DAT read: user:3>
2025-06-18T17:28:00.633Z,1750267680.633 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-06-18T17:28:00.634Z,1750267680.634 [DAT](INFO): set transmit power to 8
2025-06-18T17:28:00.635Z,1750267680.635 [DAT](INFO): setting local address to 5
2025-06-18T17:28:00.881Z,1750267680.881 [DAT](INFO): DAT read: user:4>
2025-06-18T17:28:00.882Z,1750267680.882 [DAT](INFO): DAT read: LocalAddr | 5
2025-06-18T17:28:00.882Z,1750267680.882 [DAT](INFO): set local address to 5
2025-06-18T17:28:00.884Z,1750267680.884 [DAT](INFO): Setting time to: 17:28:0 And date to:6/18/2025
2025-06-18T17:28:01.134Z,1750267681.134 [DAT](INFO): DAT read: user:5>
2025-06-18T17:28:01.135Z,1750267681.135 [DAT](INFO): DAT read: Wed Jun 18, 2025 17:28:00
2025-06-18T17:28:01.136Z,1750267681.136 [DAT](INFO): Local DAT time set to Wed Jun 18, 2025 17:28:00
2025-06-18T17:28:12.004Z,1750267692.004 [NAL9602](INFO): Powering up NAL9602
2025-06-18T17:28:22.899Z,1750267702.899 [NAL9602](INFO): NAL9602 initialized
2025-06-18T17:29:54.523Z,1750267794.523 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004440
2025-06-18T17:30:04.819Z,1750267804.819 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-06-18T17:30:14.031Z,1750267814.031 [SBIT](IMPORTANT): Beginning Startup BIT
2025-06-18T17:30:14.035Z,1750267814.035 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-06-18T17:30:18.542Z,1750267818.542 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.007954
CHAN A1 (24V): 0.013504
CHAN A2 (12V): -0.000023
CHAN A3 (5V): -0.002637
CHAN B0 (3.3V): -0.002434
CHAN B1 (3.15aV): -0.002108
CHAN B2 (3.15bV): -0.001290
CHAN B3 (GND): -0.002137
OPEN: 0.007112
Full Scale: +/- 1 mA
2025-06-18T17:30:42.745Z,1750267842.745 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-06-18T17:30:42.745Z,1750267842.745 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:30:42.780Z,1750267842.780 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:30:43.166Z,1750267843.166 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:30:43.166Z,1750267843.166 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-06-18T17:31:07.859Z,1750267867.859 [SBIT](IMPORTANT): SBIT PASSED
2025-06-18T17:31:07.859Z,1750267867.859 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-06-18T17:31:07.860Z,1750267867.860 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;
2025-06-18T17:31:07.860Z,1750267867.860 [SBIT](IMPORTANT): ElevatorServo.currLimit=20 percent;
2025-06-18T17:31:07.860Z,1750267867.860 [SBIT](IMPORTANT): ThrusterHE.bestEffortMode=1 bool;
2025-06-18T17:31:07.860Z,1750267867.860 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=269.964190 cubic_centimeter;
2025-06-18T17:31:07.861Z,1750267867.861 [SBIT](IMPORTANT): VerticalControl.massDefault=32.772906 millimeter;
2025-06-18T17:31:08.259Z,1750267868.259 [MissionManager](IMPORTANT): Started mission Startup
2025-06-18T17:31:08.259Z,1750267868.259 [Startup] Running Loop=1
2025-06-18T17:31:08.259Z,1750267868.259 [Startup](DEBUG): Aggregate::initialize Startup
2025-06-18T17:31:08.259Z,1750267868.259 [Startup:A.GoToSurface] Running Loop=1
2025-06-18T17:31:08.259Z,1750267868.259 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-18T17:31:08.260Z,1750267868.260 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-06-18T17:31:08.261Z,1750267868.261 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-06-18T17:31:08.261Z,1750267868.261 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-06-18T17:31:08.261Z,1750267868.261 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-06-18T17:31:08.262Z,1750267868.262 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-18T17:31:08.262Z,1750267868.262 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-18T17:31:08.264Z,1750267868.264 [Startup:StartupSatComms] Running Loop=1
2025-06-18T17:31:08.264Z,1750267868.264 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-06-18T17:31:08.264Z,1750267868.264 [Startup:StartupSatComms:A] Running Loop=1
2025-06-18T17:31:08.662Z,1750267868.662 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-06-18T17:31:26.940Z,1750267886.940 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-06-18T17:31:41.371Z,1750267901.371 [DVL_micro](ERROR): Failed to parse:
:SA,-01.66,+04.78,229.4
2025-06-18T17:32:03.631Z,1750267923.631 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-06-18T17:32:08.441Z,1750267928.441 [Startup:StartupSatComms:A](INFO): Timed out from 2025-06-18T17:31:08.3Z
2025-06-18T17:32:08.442Z,1750267928.442 [Startup:StartupSatComms:A] Stopped
2025-06-18T17:32:08.442Z,1750267928.442 [Startup:StartupSatComms:B] Running Loop=1
2025-06-18T17:32:08.842Z,1750267928.842 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-06-18T17:32:16.124Z,1750267936.124 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250618T155346/Courier0028.lzma
2025-06-18T17:32:17.126Z,1750267937.126 [DataOverHttps](INFO): Moved sent file to Logs/20250618T155346/Courier0028.lzma.bak
2025-06-18T17:32:17.126Z,1750267937.126 [DataOverHttps](INFO): SBD MOMSN=25226277
2025-06-18T17:32:33.242Z,1750267953.242 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250618T172731/Courier0000.lzma
2025-06-18T17:32:34.242Z,1750267954.242 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0000.lzma.bak
2025-06-18T17:32:34.242Z,1750267954.242 [DataOverHttps](INFO): SBD MOMSN=25226279
2025-06-18T17:32:40.018Z,1750267960.018 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-06-18T17:32:50.868Z,1750267970.868 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20250618T155346/Express0029.lzma
2025-06-18T17:32:51.870Z,1750267971.870 [DataOverHttps](INFO): Moved sent file to Logs/20250618T155346/Express0029.lzma.bak
2025-06-18T17:32:51.870Z,1750267971.870 [DataOverHttps](INFO): SBD MOMSN=25226282
2025-06-18T17:33:07.882Z,1750267987.882 [DataOverHttps](INFO): Sending 825 bytes from file Logs/20250618T172731/Express0001.lzma
2025-06-18T17:33:08.678Z,1750267988.678 [Startup:StartupSatComms:B](INFO): Timed out from 2025-06-18T17:32:08.4Z
2025-06-18T17:33:08.678Z,1750267988.678 [Startup:StartupSatComms:B] Stopped
2025-06-18T17:33:08.678Z,1750267988.678 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-06-18T17:33:08.678Z,1750267988.678 [Startup:StartupSatComms] Stopped
2025-06-18T17:33:08.678Z,1750267988.678 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-06-18T17:33:08.679Z,1750267988.679 [Startup](INFO): Completed Startup
2025-06-18T17:33:08.679Z,1750267988.679 [MissionManager](INFO): Startup is completed.
2025-06-18T17:33:08.680Z,1750267988.680 [MissionManager](INFO): Uninitializing Mission Startup
2025-06-18T17:33:08.680Z,1750267988.680 [Startup] Stopped
2025-06-18T17:33:08.680Z,1750267988.680 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-06-18T17:33:08.680Z,1750267988.680 [Startup:A.GoToSurface] Stopped
2025-06-18T17:33:08.680Z,1750267988.680 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-06-18T17:33:08.874Z,1750267988.874 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0001.lzma.bak
2025-06-18T17:33:08.874Z,1750267988.874 [DataOverHttps](INFO): SBD MOMSN=25226287
2025-06-18T17:33:09.100Z,1750267989.100 [MissionManager](IMPORTANT): Started mission Default
2025-06-18T17:33:09.101Z,1750267989.101 [Default] Running Loop=1
2025-06-18T17:33:09.101Z,1750267989.101 [Default](DEBUG): Aggregate::initialize Default
2025-06-18T17:33:09.101Z,1750267989.101 [Default:B.GoToSurface] Running Loop=1
2025-06-18T17:33:09.101Z,1750267989.101 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-18T17:33:09.101Z,1750267989.101 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-06-18T17:33:09.102Z,1750267989.102 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-06-18T17:33:09.102Z,1750267989.102 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-06-18T17:33:09.102Z,1750267989.102 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-06-18T17:33:09.102Z,1750267989.102 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-18T17:33:09.103Z,1750267989.103 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-18T17:33:09.103Z,1750267989.103 [Default:A.Wait] Running Loop=1
2025-06-18T17:33:09.103Z,1750267989.103 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-06-18T17:33:22.393Z,1750268002.393 [Default:A.Wait](INFO): Done Waiting.
2025-06-18T17:33:22.393Z,1750268002.393 [Default:A.Wait] Stopped
2025-06-18T17:33:22.393Z,1750268002.393 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T17:33:22.825Z,1750268002.825 [Default:CheckIn] Running Loop=1
2025-06-18T17:33:22.825Z,1750268002.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T17:33:22.825Z,1750268002.825 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T17:33:23.194Z,1750268003.194 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-06-18T17:33:26.415Z,1750268006.415 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-18T17:33:43.801Z,1750268023.801 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-06-18T17:33:43.801Z,1750268023.801 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:33:43.811Z,1750268023.811 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:33:44.257Z,1750268024.257 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:33:44.257Z,1750268024.257 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-06-18T17:34:07.633Z,1750268047.633 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-06-18T17:34:07.634Z,1750268047.634 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-06-18T17:34:07.634Z,1750268047.634 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2025-06-18T17:34:07.643Z,1750268047.643 [BPC1](INFO): Received data from all battery sticks.
2025-06-18T17:36:44.813Z,1750268204.813 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-06-18T17:36:44.813Z,1750268204.813 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:36:44.823Z,1750268204.823 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:36:45.229Z,1750268205.229 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:36:45.229Z,1750268205.229 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-06-18T17:38:22.978Z,1750268302.978 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-06-18T17:33:22.8Z
2025-06-18T17:38:22.978Z,1750268302.978 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T17:38:22.978Z,1750268302.978 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T17:38:23.372Z,1750268303.372 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-06-18T17:38:24.194Z,1750268304.194 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-06-18T17:38:24.194Z,1750268304.194 [NAL9602] Data Fault, FailCount= 1
2025-06-18T17:38:24.194Z,1750268304.194 [NAL9602](ERROR): Data Fault
2025-06-18T17:38:24.211Z,1750268304.211 [CBIT](ERROR): Data Fault in component: NAL9602
2025-06-18T17:38:24.567Z,1750268304.567 [NAL9602](INFO): Powering down
2025-06-18T17:38:25.404Z,1750268305.404 [CBIT](INFO): Clearing failed state for component NAL9602
2025-06-18T17:38:25.404Z,1750268305.404 [NAL9602] No Fault, FailCount= 1
2025-06-18T17:38:29.896Z,1750268309.896 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250618T172731/Courier0004.lzma
2025-06-18T17:38:30.898Z,1750268310.898 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0004.lzma.bak
2025-06-18T17:38:30.898Z,1750268310.898 [DataOverHttps](INFO): SBD MOMSN=25226313
2025-06-18T17:38:47.992Z,1750268327.992 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250618T172731/Express0005.lzma
2025-06-18T17:38:48.994Z,1750268328.994 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0005.lzma.bak
2025-06-18T17:38:48.994Z,1750268328.994 [DataOverHttps](INFO): SBD MOMSN=25226315
2025-06-18T17:38:50.858Z,1750268330.858 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T17:38:50.858Z,1750268330.858 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T17:38:50.858Z,1750268330.858 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T17:38:54.866Z,1750268334.866 [NAL9602](INFO): Powering up NAL9602
2025-06-18T17:39:05.784Z,1750268345.784 [NAL9602](INFO): NAL9602 initialized
2025-06-18T17:39:45.774Z,1750268385.774 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-06-18T17:39:45.774Z,1750268385.774 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:39:45.785Z,1750268385.785 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:39:46.221Z,1750268386.221 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:39:46.221Z,1750268386.221 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-06-18T17:41:51.013Z,1750268511.013 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00I,-00954,-00373,+01124,+00000,I
2025-06-18T17:41:51.013Z,1750268511.013 [DVL_micro](ERROR): Failed to parse:
:TS,00I,-00954,-00373,+01124,+00000,I
2025-06-18T17:42:01.792Z,1750268521.792 [CommandExec](IMPORTANT): got command configSet list
2025-06-18T17:42:01.793Z,1750268521.793 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-06-18T17:42:01.794Z,1750268521.794 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;
2025-06-18T17:42:01.795Z,1750268521.795 [CommandExec](IMPORTANT): ElevatorServo.currLimit=20 percent;
2025-06-18T17:42:01.795Z,1750268521.795 [CommandExec](IMPORTANT): ThrusterHE.bestEffortMode=1 bool;
2025-06-18T17:42:01.796Z,1750268521.796 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=269.964190 cubic_centimeter;
2025-06-18T17:42:01.797Z,1750268521.797 [CommandExec](IMPORTANT): VerticalControl.massDefault=32.772906 millimeter;
2025-06-18T17:42:13.863Z,1750268533.863 [CommandExec](IMPORTANT): got command get DVL_micro.loadAtStartup
2025-06-18T17:42:13.863Z,1750268533.863 [CommandExec](IMPORTANT): DVL_micro.loadAtStartup 1 bool
2025-06-18T17:42:46.787Z,1750268566.787 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-06-18T17:42:46.787Z,1750268566.787 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:42:46.799Z,1750268566.799 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:42:47.187Z,1750268567.187 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:42:47.187Z,1750268567.187 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-06-18T17:43:25.558Z,1750268605.558 [CommandExec](IMPORTANT): got command burn on
2025-06-18T17:43:25.558Z,1750268605.558 [CommandExec](IMPORTANT): Activating dropweight wire
2025-06-18T17:43:36.878Z,1750268616.878 [DVL_micro](ERROR): Failed to parse:
:SA,-01.66,+04.80,229.1
2025-06-18T17:43:51.450Z,1750268631.450 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T17:43:51.450Z,1750268631.450 [Default:CheckIn:C.Wait] Stopped
2025-06-18T17:43:51.450Z,1750268631.450 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T17:43:51.450Z,1750268631.450 [Default:CheckIn:D] Running Loop=1
2025-06-18T17:43:51.826Z,1750268631.826 [Default:CheckIn:D] Stopped
2025-06-18T17:43:51.826Z,1750268631.826 [Default:CheckIn:E] Running Loop=1
2025-06-18T17:43:52.226Z,1750268632.226 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.712091 min
2025-06-18T17:43:52.226Z,1750268632.226 [Default:CheckIn:E] Stopped
2025-06-18T17:43:52.227Z,1750268632.227 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T17:43:52.227Z,1750268632.227 [Default:CheckIn] Stopped
2025-06-18T17:43:52.227Z,1750268632.227 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T17:43:52.227Z,1750268632.227 [Default:CheckIn](INFO): Running loop #2
2025-06-18T17:43:52.227Z,1750268632.227 [Default:CheckIn] Running Loop=2
2025-06-18T17:43:52.227Z,1750268632.227 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T17:43:52.227Z,1750268632.227 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T17:45:47.829Z,1750268747.829 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-06-18T17:45:47.829Z,1750268747.829 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:45:47.839Z,1750268747.839 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:45:48.242Z,1750268748.242 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:45:48.242Z,1750268748.242 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-06-18T17:45:55.713Z,1750268755.713 [CommandExec](IMPORTANT): got command burn on
2025-06-18T17:45:55.713Z,1750268755.713 [CommandExec](IMPORTANT): Activating dropweight wire
2025-06-18T17:46:11.662Z,1750268771.662 [CommandExec](IMPORTANT): got command burn off
2025-06-18T17:46:11.663Z,1750268771.663 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-06-18T17:46:18.432Z,1750268778.432 [CommandExec](IMPORTANT): got command burn on
2025-06-18T17:46:18.432Z,1750268778.432 [CommandExec](IMPORTANT): Activating dropweight wire
2025-06-18T17:47:08.848Z,1750268828.848 [CommandExec](IMPORTANT): got command get platform_battery_voltage
2025-06-18T17:47:08.848Z,1750268828.848 [CommandExec](IMPORTANT): platform_battery_voltage 16.096001 V
2025-06-18T17:47:47.834Z,1750268867.834 [Sonardyne_Nano](INFO): Battery at maximum, disabling charging
2025-06-18T17:48:01.972Z,1750268881.972 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2025-06-18T17:48:48.839Z,1750268928.839 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-06-18T17:48:48.839Z,1750268928.839 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:48:48.877Z,1750268928.877 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:48:49.279Z,1750268929.279 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:48:49.279Z,1750268929.279 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-06-18T17:48:52.505Z,1750268932.505 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-06-18T17:43:52.2Z
2025-06-18T17:48:52.505Z,1750268932.505 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T17:48:52.505Z,1750268932.505 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T17:48:59.000Z,1750268940.000 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250618T172731/Courier0007.lzma
2025-06-18T17:49:01.002Z,1750268941.002 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0007.lzma.bak
2025-06-18T17:49:01.002Z,1750268941.002 [DataOverHttps](INFO): SBD MOMSN=25226356
2025-06-18T17:49:06.615Z,1750268946.615 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-06-18T17:49:06.615Z,1750268946.615 [NAL9602] Data Fault, FailCount= 2
2025-06-18T17:49:06.615Z,1750268946.615 [NAL9602](ERROR): Data Fault
2025-06-18T17:49:06.652Z,1750268946.652 [CBIT](ERROR): Data Fault in component: NAL9602
2025-06-18T17:49:07.014Z,1750268947.014 [NAL9602](INFO): Powering down
2025-06-18T17:49:07.852Z,1750268947.852 [CBIT](INFO): Clearing failed state for component NAL9602
2025-06-18T17:49:07.852Z,1750268947.852 [NAL9602] No Fault, FailCount= 2
2025-06-18T17:49:17.837Z,1750268957.837 [DataOverHttps](INFO): Sending 588 bytes from file Logs/20250618T172731/Express0008.lzma
2025-06-18T17:49:18.838Z,1750268958.838 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0008.lzma.bak
2025-06-18T17:49:18.838Z,1750268958.838 [DataOverHttps](INFO): SBD MOMSN=25226359
2025-06-18T17:49:20.757Z,1750268960.757 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T17:49:20.757Z,1750268960.757 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T17:49:20.757Z,1750268960.757 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T17:49:37.327Z,1750268977.327 [NAL9602](INFO): Powering up NAL9602
2025-06-18T17:49:48.220Z,1750268988.220 [NAL9602](INFO): NAL9602 initialized
2025-06-18T17:51:49.840Z,1750269109.840 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-06-18T17:51:49.840Z,1750269109.840 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:51:49.851Z,1750269109.851 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:51:50.262Z,1750269110.262 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:51:50.262Z,1750269110.262 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-06-18T17:53:26.893Z,1750269206.893 [CommandExec](IMPORTANT): got command burn off
2025-06-18T17:53:26.893Z,1750269206.893 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-06-18T17:54:21.344Z,1750269261.344 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T17:54:21.344Z,1750269261.344 [Default:CheckIn:C.Wait] Stopped
2025-06-18T17:54:21.344Z,1750269261.344 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T17:54:21.344Z,1750269261.344 [Default:CheckIn:D] Running Loop=1
2025-06-18T17:54:21.735Z,1750269261.735 [Default:CheckIn:D] Stopped
2025-06-18T17:54:21.735Z,1750269261.735 [Default:CheckIn:E] Running Loop=1
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.210571 min
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn:E] Stopped
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn] Stopped
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn](INFO): Running loop #3
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn] Running Loop=3
2025-06-18T17:54:22.142Z,1750269262.142 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T17:54:22.143Z,1750269262.143 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T17:54:50.821Z,1750269290.821 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-06-18T17:54:50.822Z,1750269290.822 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:54:50.832Z,1750269290.832 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:54:51.243Z,1750269291.243 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:54:51.243Z,1750269291.243 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-06-18T17:57:51.876Z,1750269471.876 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2025-06-18T17:57:51.877Z,1750269471.876 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T17:57:51.887Z,1750269471.887 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T17:57:52.309Z,1750269472.309 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T17:57:52.310Z,1750269472.310 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2025-06-18T17:59:22.410Z,1750269562.410 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-06-18T17:54:22.1Z
2025-06-18T17:59:22.410Z,1750269562.410 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T17:59:22.410Z,1750269562.410 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T17:59:29.247Z,1750269569.247 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250618T172731/Courier0010.lzma
2025-06-18T17:59:30.243Z,1750269570.243 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0010.lzma.bak
2025-06-18T17:59:30.243Z,1750269570.243 [DataOverHttps](INFO): SBD MOMSN=25226473
2025-06-18T17:59:47.009Z,1750269587.009 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250618T172731/Express0011.lzma
2025-06-18T17:59:48.010Z,1750269588.010 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0011.lzma.bak
2025-06-18T17:59:48.010Z,1750269588.010 [DataOverHttps](INFO): SBD MOMSN=25226475
2025-06-18T17:59:50.286Z,1750269590.286 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T17:59:50.286Z,1750269590.286 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T17:59:50.286Z,1750269590.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T17:59:51.510Z,1750269591.510 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-06-18T17:59:51.510Z,1750269591.510 [NAL9602] Data Fault, FailCount= 3
2025-06-18T17:59:51.510Z,1750269591.510 [NAL9602](ERROR): Data Fault
2025-06-18T17:59:51.573Z,1750269591.573 [CBIT](ERROR): Data Fault in component: NAL9602
2025-06-18T17:59:51.886Z,1750269591.886 [NAL9602](INFO): Powering down
2025-06-18T17:59:52.727Z,1750269592.727 [CBIT](INFO): Clearing failed state for component NAL9602
2025-06-18T17:59:52.727Z,1750269592.727 [NAL9602] No Fault, FailCount= 3
2025-06-18T18:00:22.186Z,1750269622.186 [NAL9602](INFO): Powering up NAL9602
2025-06-18T18:00:33.130Z,1750269633.130 [NAL9602](INFO): NAL9602 initialized
2025-06-18T18:00:52.913Z,1750269652.913 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2025-06-18T18:00:52.913Z,1750269652.913 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T18:00:52.942Z,1750269652.942 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T18:00:53.353Z,1750269653.353 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T18:00:53.353Z,1750269653.353 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2025-06-18T18:03:53.965Z,1750269833.965 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2025-06-18T18:03:53.965Z,1750269833.965 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T18:03:53.976Z,1750269833.976 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T18:03:54.390Z,1750269834.390 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T18:03:54.390Z,1750269834.390 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2025-06-18T18:04:50.955Z,1750269890.955 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:04:50.956Z,1750269890.956 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:04:50.956Z,1750269890.956 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:04:50.956Z,1750269890.956 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:04:51.374Z,1750269891.374 [Default:CheckIn:D] Stopped
2025-06-18T18:04:51.374Z,1750269891.374 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:04:51.766Z,1750269891.766 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.704547 min
2025-06-18T18:04:51.766Z,1750269891.766 [Default:CheckIn:E] Stopped
2025-06-18T18:04:51.766Z,1750269891.766 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:04:51.766Z,1750269891.766 [Default:CheckIn] Stopped
2025-06-18T18:04:51.766Z,1750269891.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:04:51.766Z,1750269891.766 [Default:CheckIn](INFO): Running loop #4
2025-06-18T18:04:51.766Z,1750269891.766 [Default:CheckIn] Running Loop=4
2025-06-18T18:04:51.767Z,1750269891.767 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:04:51.767Z,1750269891.767 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:06:54.983Z,1750270014.983 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2025-06-18T18:06:54.983Z,1750270014.983 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T18:06:54.994Z,1750270014.994 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T18:06:55.430Z,1750270015.430 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T18:06:55.430Z,1750270015.430 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2025-06-18T18:09:51.941Z,1750270191.941 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-06-18T18:04:51.8Z
2025-06-18T18:09:51.941Z,1750270191.941 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:09:51.941Z,1750270191.941 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:09:56.008Z,1750270196.008 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2025-06-18T18:09:56.008Z,1750270196.008 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T18:09:56.023Z,1750270196.023 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T18:09:56.436Z,1750270196.436 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T18:09:56.437Z,1750270196.437 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2025-06-18T18:09:59.639Z,1750270199.639 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250618T172731/Courier0013.lzma
2025-06-18T18:10:00.642Z,1750270200.642 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0013.lzma.bak
2025-06-18T18:10:00.642Z,1750270200.642 [DataOverHttps](INFO): SBD MOMSN=25226518
2025-06-18T18:10:16.560Z,1750270216.560 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250618T172731/Express0014.lzma
2025-06-18T18:10:17.563Z,1750270217.563 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0014.lzma.bak
2025-06-18T18:10:17.563Z,1750270217.563 [DataOverHttps](INFO): SBD MOMSN=25226520
2025-06-18T18:10:19.438Z,1750270219.438 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:10:19.438Z,1750270219.438 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:10:19.438Z,1750270219.438 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:10:36.370Z,1750270236.370 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-06-18T18:10:36.370Z,1750270236.370 [NAL9602] Data Fault, FailCount= 4
2025-06-18T18:10:36.370Z,1750270236.370 [NAL9602](ERROR): Data Fault
2025-06-18T18:10:36.387Z,1750270236.387 [CBIT](ERROR): Data Fault in component: NAL9602
2025-06-18T18:10:36.774Z,1750270236.774 [NAL9602](INFO): Powering down
2025-06-18T18:10:37.627Z,1750270237.627 [CBIT](INFO): Clearing failed state for component NAL9602
2025-06-18T18:10:37.627Z,1750270237.627 [NAL9602] No Fault, FailCount= 4
2025-06-18T18:11:07.076Z,1750270267.076 [NAL9602](INFO): Powering up NAL9602
2025-06-18T18:11:17.979Z,1750270277.979 [NAL9602](INFO): NAL9602 initialized
2025-06-18T18:12:56.988Z,1750270376.988 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2025-06-18T18:12:56.988Z,1750270376.988 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-18T18:12:57.007Z,1750270377.007 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-18T18:12:57.414Z,1750270377.414 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-18T18:12:57.414Z,1750270377.414 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2025-06-18T18:14:20.993Z,1750270460.993 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181417.00,A,3648.14575,N,12147.25388,W,1.575,161.69,180625,,,A*7F
2025-06-18T18:14:20.996Z,1750270460.996 [NAL9602](INFO): GPS fix at 20250618T181417: (36.802429, -121.787565)
2025-06-18T18:14:53.318Z,1750270493.318 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:14:57.420Z,1750270497.420 [DVL_micro](ERROR): DVL uart error: serial timeout
2025-06-18T18:14:57.420Z,1750270497.420 [DVL_micro] Communications Fault, FailCount= 1
2025-06-18T18:14:57.420Z,1750270497.420 [DVL_micro](ERROR): Communications Fault
2025-06-18T18:14:57.421Z,1750270497.421 [DVL_micro](ERROR): Failed to parse:
2025-06-18T18:14:57.491Z,1750270497.491 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-06-18T18:14:57.856Z,1750270497.856 [DVL_micro](INFO): Powering down
2025-06-18T18:14:58.652Z,1750270498.652 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-06-18T18:14:58.652Z,1750270498.652 [DVL_micro] No Fault, FailCount= 1
2025-06-18T18:15:19.990Z,1750270519.990 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:15:19.991Z,1750270519.991 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:15:19.991Z,1750270519.991 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:15:19.991Z,1750270519.991 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:15:20.392Z,1750270520.392 [Default:CheckIn:D] Stopped
2025-06-18T18:15:20.392Z,1750270520.392 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:15:20.801Z,1750270520.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.188180 min
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn:E] Stopped
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn] Stopped
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn](INFO): Running loop #5
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn] Running Loop=5
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:15:20.802Z,1750270520.802 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:15:22.806Z,1750270522.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181519.00,A,3648.15185,N,12147.22626,W,0.039,20.59,180625,,,A*47
2025-06-18T18:15:22.808Z,1750270522.808 [NAL9602](INFO): GPS fix at 20250618T181519: (36.802531, -121.787104)
2025-06-18T18:15:22.839Z,1750270522.839 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:15:22.839Z,1750270522.839 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:15:29.904Z,1750270529.904 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250618T172731/Courier0016.lzma
2025-06-18T18:15:30.906Z,1750270530.906 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0016.lzma.bak
2025-06-18T18:15:30.906Z,1750270530.906 [DataOverHttps](INFO): SBD MOMSN=25226548
2025-06-18T18:15:38.285Z,1750270538.285 [NAL9602](INFO): SBD MO Status=0, MOMSN=21746, MT Status=0, MTMSN=0
2025-06-18T18:15:38.285Z,1750270538.285 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:15:49.537Z,1750270549.537 [DataOverHttps](INFO): Sending 419 bytes from file Logs/20250618T172731/Express0017.lzma
2025-06-18T18:15:50.538Z,1750270550.538 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0017.lzma.bak
2025-06-18T18:15:50.538Z,1750270550.538 [DataOverHttps](IMPORTANT): SBD MOMSN=25226552, MTMSN=20250618T181549
2025-06-18T18:15:52.415Z,1750270552.415 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:15:52.415Z,1750270552.415 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:15:52.415Z,1750270552.415 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:15:58.312Z,1750270558.312 [DataOverHttps](INFO): Received command: ibit
2025-06-18T18:15:58.321Z,1750270558.321 [CommandExec](IMPORTANT): got command ibit
2025-06-18T18:15:58.489Z,1750270558.489 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-06-18T18:15:58.489Z,1750270558.489 [IBIT](IMPORTANT): Beginning control surface checks.
2025-06-18T18:15:58.493Z,1750270558.493 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-06-18T18:15:59.313Z,1750270559.313 [DataOverHttps](IMPORTANT): SBD MTMSN=20250618T181558
2025-06-18T18:16:00.076Z,1750270560.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181556.00,A,3648.15081,N,12147.22553,W,0.058,20.59,180625,,,A*4F
2025-06-18T18:16:00.078Z,1750270560.078 [NAL9602](INFO): GPS fix at 20250618T181556: (36.802514, -121.787092)
2025-06-18T18:16:02.912Z,1750270562.912 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181559.00,A,3648.15073,N,12147.22546,W,0.039,20.59,180625,,,A*4E
2025-06-18T18:16:02.915Z,1750270562.915 [NAL9602](INFO): GPS fix at 20250618T181559: (36.802512, -121.787091)
2025-06-18T18:16:03.124Z,1750270563.124 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005438
CHAN A1 (24V): 0.003493
CHAN A2 (12V): -0.004317
CHAN A3 (5V): -0.002069
CHAN B0 (3.3V): -0.001104
CHAN B1 (3.15aV): -0.001138
CHAN B2 (3.15bV): -0.001014
CHAN B3 (GND): -0.000029
OPEN: 0.006986
Full Scale: +/- 1 mA
2025-06-18T18:16:05.731Z,1750270565.731 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181602.00,A,3648.15074,N,12147.22547,W,0.019,20.59,180625,,,A*47
2025-06-18T18:16:05.738Z,1750270565.738 [NAL9602](INFO): GPS fix at 20250618T181602: (36.802512, -121.787091)
2025-06-18T18:16:07.036Z,1750270567.036 [DataOverHttps](INFO): Received command: failc
2025-06-18T18:16:07.065Z,1750270567.065 [CommandExec](IMPORTANT): got command failComponent
2025-06-18T18:16:07.065Z,1750270567.065 [CommandExec](IMPORTANT): Failed components:
2025-06-18T18:16:07.066Z,1750270567.066 [CommandExec](IMPORTANT): No failed Components.
2025-06-18T18:16:08.960Z,1750270568.960 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181605.00,A,3648.15077,N,12147.22547,W,0.058,20.59,180625,,,A*46
2025-06-18T18:16:08.962Z,1750270568.962 [NAL9602](INFO): GPS fix at 20250618T181605: (36.802513, -121.787091)
2025-06-18T18:16:11.786Z,1750270571.786 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181608.00,A,3648.15074,N,12147.22540,W,0.000,20.59,180625,,,A*42
2025-06-18T18:16:11.789Z,1750270571.789 [NAL9602](INFO): GPS fix at 20250618T181608: (36.802512, -121.787090)
2025-06-18T18:16:15.028Z,1750270575.028 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181611.00,A,3648.15068,N,12147.22527,W,0.039,20.59,180625,,,A*4C
2025-06-18T18:16:15.031Z,1750270575.031 [NAL9602](INFO): GPS fix at 20250618T181611: (36.802511, -121.787088)
2025-06-18T18:16:17.859Z,1750270577.859 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181614.00,A,3648.15065,N,12147.22512,W,0.058,20.59,180625,,,A*45
2025-06-18T18:16:17.862Z,1750270577.862 [NAL9602](INFO): GPS fix at 20250618T181614: (36.802511, -121.787085)
2025-06-18T18:16:21.082Z,1750270581.082 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181617.00,A,3648.15061,N,12147.22496,W,0.019,20.59,180625,,,A*4A
2025-06-18T18:16:21.085Z,1750270581.085 [NAL9602](INFO): GPS fix at 20250618T181617: (36.802510, -121.787083)
2025-06-18T18:16:23.907Z,1750270583.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181620.00,A,3648.15059,N,12147.22485,W,0.078,20.59,180625,,,A*40
2025-06-18T18:16:23.909Z,1750270583.909 [NAL9602](INFO): GPS fix at 20250618T181620: (36.802510, -121.787081)
2025-06-18T18:16:27.139Z,1750270587.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181623.00,A,3648.15061,N,12147.22485,W,0.078,20.59,180625,,,D*4D
2025-06-18T18:16:27.141Z,1750270587.141 [NAL9602](INFO): GPS fix at 20250618T181623: (36.802510, -121.787081)
2025-06-18T18:16:29.967Z,1750270589.967 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181626.00,A,3648.15058,N,12147.22478,W,0.019,20.59,180625,,,D*47
2025-06-18T18:16:29.975Z,1750270589.975 [NAL9602](INFO): GPS fix at 20250618T181626: (36.802510, -121.787080)
2025-06-18T18:16:32.799Z,1750270592.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181629.00,A,3648.15052,N,12147.22472,W,0.097,20.59,180625,,,D*4E
2025-06-18T18:16:32.806Z,1750270592.806 [NAL9602](INFO): GPS fix at 20250618T181629: (36.802509, -121.787079)
2025-06-18T18:16:36.028Z,1750270596.028 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181632.00,A,3648.15049,N,12147.22460,W,0.058,20.59,180625,,,D*4E
2025-06-18T18:16:36.030Z,1750270596.030 [NAL9602](INFO): GPS fix at 20250618T181632: (36.802508, -121.787077)
2025-06-18T18:16:38.869Z,1750270598.869 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181635.00,A,3648.15049,N,12147.22444,W,0.039,20.59,180625,,,D*48
2025-06-18T18:16:38.873Z,1750270598.873 [NAL9602](INFO): GPS fix at 20250618T181635: (36.802508, -121.787074)
2025-06-18T18:16:42.091Z,1750270602.091 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181638.00,A,3648.15040,N,12147.22427,W,0.019,20.59,180625,,,D*4B
2025-06-18T18:16:42.093Z,1750270602.093 [NAL9602](INFO): GPS fix at 20250618T181638: (36.802507, -121.787071)
2025-06-18T18:16:44.919Z,1750270604.919 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181641.00,A,3648.15031,N,12147.22430,W,0.039,20.59,180625,,,D*47
2025-06-18T18:16:44.921Z,1750270604.921 [NAL9602](INFO): GPS fix at 20250618T181641: (36.802505, -121.787072)
2025-06-18T18:16:44.962Z,1750270604.962 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802505 Longitude: -121.787071
2025-06-18T18:16:45.354Z,1750270605.354 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.937000
2025-06-18T18:16:45.354Z,1750270605.354 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-06-18T18:16:45.354Z,1750270605.354 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-06-18T18:16:45.743Z,1750270605.743 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-06-18T18:16:45.743Z,1750270605.743 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-06-18T18:16:45.743Z,1750270605.743 [IBIT](IMPORTANT): Pressure:10.525021 PSI
2025-06-18T18:16:45.744Z,1750270605.744 [IBIT](IMPORTANT): Humidity:6.732999 %
2025-06-18T18:16:46.158Z,1750270606.158 [IBIT](IMPORTANT): Vehicle Pitch:-2.390962 degrees
2025-06-18T18:16:46.158Z,1750270606.158 [IBIT](IMPORTANT): Vehicle Roll:4.794064 degrees
2025-06-18T18:16:46.159Z,1750270606.159 [IBIT](IMPORTANT): Vehicle Heading:191.901215 degrees
2025-06-18T18:16:46.544Z,1750270606.544 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-06-18T18:16:46.544Z,1750270606.544 [IBIT](IMPORTANT): buoyancyNeutral: 269.964203 cc
2025-06-18T18:16:46.544Z,1750270606.544 [IBIT](IMPORTANT): massDefault: 3.277291 cm
2025-06-18T18:16:46.545Z,1750270606.545 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2025-06-18T18:16:46.545Z,1750270606.545 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-06-18T18:16:46.545Z,1750270606.545 [IBIT](IMPORTANT): IBIT PASSED
2025-06-18T18:17:17.638Z,1750270637.638 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:20:53.007Z,1750270853.007 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:20:53.007Z,1750270853.007 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:20:53.007Z,1750270853.007 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:20:53.007Z,1750270853.007 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:20:53.422Z,1750270853.422 [Default:CheckIn:D] Stopped
2025-06-18T18:20:53.422Z,1750270853.422 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.738684 min
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn:E] Stopped
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn] Stopped
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn](INFO): Running loop #6
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn] Running Loop=6
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:20:53.813Z,1750270853.813 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:20:55.841Z,1750270855.841 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182052.00,A,3648.14347,N,12147.21318,W,0.019,20.59,180625,,,D*4F
2025-06-18T18:20:55.843Z,1750270855.843 [NAL9602](INFO): GPS fix at 20250618T182052: (36.802391, -121.786886)
2025-06-18T18:20:55.854Z,1750270855.854 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:20:55.854Z,1750270855.854 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:21:03.252Z,1750270863.252 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250618T172731/Courier0019.lzma
2025-06-18T18:21:04.254Z,1750270864.254 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0019.lzma.bak
2025-06-18T18:21:04.254Z,1750270864.254 [DataOverHttps](INFO): SBD MOMSN=25226572
2025-06-18T18:21:16.016Z,1750270876.016 [NAL9602](INFO): SBD MO Status=0, MOMSN=21747, MT Status=0, MTMSN=0
2025-06-18T18:21:16.016Z,1750270876.016 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:21:20.207Z,1750270880.207 [DataOverHttps](INFO): Sending 1135 bytes from file Logs/20250618T172731/Express0020.lzma
2025-06-18T18:21:21.206Z,1750270881.206 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0020.lzma.bak
2025-06-18T18:21:21.206Z,1750270881.206 [DataOverHttps](INFO): SBD MOMSN=25226575
2025-06-18T18:21:39.748Z,1750270899.748 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20250618T172731/Express0021.lzma
2025-06-18T18:21:40.751Z,1750270900.751 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0021.lzma.bak
2025-06-18T18:21:40.751Z,1750270900.751 [DataOverHttps](INFO): SBD MOMSN=25226622
2025-06-18T18:21:42.704Z,1750270902.704 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:21:42.704Z,1750270902.704 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:21:42.704Z,1750270902.704 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:21:46.732Z,1750270906.732 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:26:43.279Z,1750271203.279 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:26:43.279Z,1750271203.279 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:26:43.279Z,1750271203.279 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:26:43.279Z,1750271203.279 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:26:43.687Z,1750271203.687 [Default:CheckIn:D] Stopped
2025-06-18T18:26:43.687Z,1750271203.687 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.576440 min
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn:E] Stopped
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn] Stopped
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn](INFO): Running loop #7
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn] Running Loop=7
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:26:44.089Z,1750271204.089 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:26:46.103Z,1750271206.103 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182645.00,A,3648.14002,N,12147.21236,W,0.019,20.59,180625,,,D*40
2025-06-18T18:26:46.113Z,1750271206.113 [NAL9602](INFO): GPS fix at 20250618T182645: (36.802334, -121.786873)
2025-06-18T18:26:46.124Z,1750271206.124 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:26:46.124Z,1750271206.124 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:26:53.940Z,1750271213.940 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0024.lzma
2025-06-18T18:26:54.942Z,1750271214.942 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0024.lzma.bak
2025-06-18T18:26:54.942Z,1750271214.942 [DataOverHttps](INFO): SBD MOMSN=25226633
2025-06-18T18:26:56.214Z,1750271216.214 [NAL9602](INFO): SBD MO Status=0, MOMSN=21748, MT Status=0, MTMSN=0
2025-06-18T18:26:56.214Z,1750271216.214 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:27:11.164Z,1750271231.164 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250618T172731/Express0026.lzma
2025-06-18T18:27:12.166Z,1750271232.166 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0026.lzma.bak
2025-06-18T18:27:12.166Z,1750271232.166 [DataOverHttps](INFO): SBD MOMSN=25226636
2025-06-18T18:27:13.982Z,1750271233.982 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:27:13.982Z,1750271233.982 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:27:13.982Z,1750271233.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:27:26.900Z,1750271246.900 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:32:14.579Z,1750271534.579 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:32:14.580Z,1750271534.580 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:32:14.580Z,1750271534.580 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:32:14.596Z,1750271534.596 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:32:14.958Z,1750271534.958 [Default:CheckIn:D] Stopped
2025-06-18T18:32:14.958Z,1750271534.958 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:32:15.363Z,1750271535.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.097628 min
2025-06-18T18:32:15.364Z,1750271535.364 [Default:CheckIn:E] Stopped
2025-06-18T18:32:15.364Z,1750271535.364 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:32:15.364Z,1750271535.364 [Default:CheckIn] Stopped
2025-06-18T18:32:15.364Z,1750271535.364 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:32:15.364Z,1750271535.364 [Default:CheckIn](INFO): Running loop #8
2025-06-18T18:32:15.364Z,1750271535.364 [Default:CheckIn] Running Loop=8
2025-06-18T18:32:15.364Z,1750271535.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:32:15.365Z,1750271535.365 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:32:17.381Z,1750271537.381 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183216.00,A,3648.13828,N,12147.20670,W,0.019,20.59,180625,,,D*43
2025-06-18T18:32:17.383Z,1750271537.383 [NAL9602](INFO): GPS fix at 20250618T183216: (36.802305, -121.786778)
2025-06-18T18:32:17.393Z,1750271537.393 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:32:17.393Z,1750271537.393 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:32:25.536Z,1750271545.536 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250618T172731/Courier0028.lzma
2025-06-18T18:32:26.538Z,1750271546.538 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0028.lzma.bak
2025-06-18T18:32:26.538Z,1750271546.538 [DataOverHttps](INFO): SBD MOMSN=25226650
2025-06-18T18:32:43.712Z,1750271563.712 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250618T172731/Express0029.lzma
2025-06-18T18:32:44.714Z,1750271564.714 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0029.lzma.bak
2025-06-18T18:32:44.714Z,1750271564.714 [DataOverHttps](INFO): SBD MOMSN=25226653
2025-06-18T18:32:46.495Z,1750271566.495 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:32:46.495Z,1750271566.495 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:32:46.495Z,1750271566.495 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:33:14.354Z,1750271594.354 [NAL9602](INFO): SBD MO Status=2, MOMSN=21749, MT Status=2, MTMSN=0
2025-06-18T18:33:14.354Z,1750271594.354 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T18:33:36.248Z,1750271616.248 [DVL_micro](ERROR): DVL uart error: serial timeout
2025-06-18T18:33:36.248Z,1750271616.248 [DVL_micro] Communications Fault, FailCount= 1
2025-06-18T18:33:36.248Z,1750271616.248 [DVL_micro](ERROR): Communications Fault
2025-06-18T18:33:36.248Z,1750271616.248 [DVL_micro](ERROR): Failed to parse:
2025-06-18T18:33:36.273Z,1750271616.273 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-06-18T18:33:36.668Z,1750271616.668 [DVL_micro](INFO): Powering down
2025-06-18T18:33:36.981Z,1750271616.981 [NAL9602](INFO): SBD MO Status=0, MOMSN=21749, MT Status=0, MTMSN=0
2025-06-18T18:33:36.981Z,1750271616.981 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:33:37.406Z,1750271617.406 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-06-18T18:33:37.406Z,1750271617.406 [DVL_micro] No Fault, FailCount= 1
2025-06-18T18:34:07.680Z,1750271647.680 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:37:47.143Z,1750271867.143 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:37:47.143Z,1750271867.143 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:37:47.143Z,1750271867.143 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:37:47.143Z,1750271867.143 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:37:47.475Z,1750271867.475 [Default:CheckIn:D] Stopped
2025-06-18T18:37:47.475Z,1750271867.475 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:37:47.899Z,1750271867.899 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.639575 min
2025-06-18T18:37:47.899Z,1750271867.899 [Default:CheckIn:E] Stopped
2025-06-18T18:37:47.900Z,1750271867.900 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:37:47.900Z,1750271867.900 [Default:CheckIn] Stopped
2025-06-18T18:37:47.900Z,1750271867.900 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:37:47.900Z,1750271867.900 [Default:CheckIn](INFO): Running loop #9
2025-06-18T18:37:47.900Z,1750271867.900 [Default:CheckIn] Running Loop=9
2025-06-18T18:37:47.900Z,1750271867.900 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:37:47.900Z,1750271867.900 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:37:49.884Z,1750271869.884 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183749.00,A,3648.14256,N,12147.21626,W,0.019,20.59,180625,,,D*4A
2025-06-18T18:37:49.886Z,1750271869.886 [NAL9602](INFO): GPS fix at 20250618T183749: (36.802376, -121.786938)
2025-06-18T18:37:49.921Z,1750271869.921 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:37:49.921Z,1750271869.921 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:37:58.180Z,1750271878.180 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0031.lzma
2025-06-18T18:37:59.183Z,1750271879.183 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0031.lzma.bak
2025-06-18T18:37:59.183Z,1750271879.183 [DataOverHttps](INFO): SBD MOMSN=25226663
2025-06-18T18:38:00.391Z,1750271880.391 [NAL9602](INFO): SBD MO Status=0, MOMSN=21750, MT Status=0, MTMSN=0
2025-06-18T18:38:00.391Z,1750271880.391 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:38:16.312Z,1750271896.312 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250618T172731/Express0032.lzma
2025-06-18T18:38:17.314Z,1750271897.314 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0032.lzma.bak
2025-06-18T18:38:17.314Z,1750271897.314 [DataOverHttps](INFO): SBD MOMSN=25226666
2025-06-18T18:38:18.992Z,1750271898.992 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:38:18.992Z,1750271898.992 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:38:18.992Z,1750271898.992 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:38:31.103Z,1750271911.103 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:41:42.274Z,1750272102.274 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-06-18T18:41:42.274Z,1750272102.274 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-06-18T18:41:42.275Z,1750272102.275 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2025-06-18T18:41:42.278Z,1750272102.278 [BPC1](INFO): Received data from all battery sticks.
2025-06-18T18:43:19.659Z,1750272199.659 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:43:19.659Z,1750272199.659 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:43:19.659Z,1750272199.659 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:43:19.659Z,1750272199.659 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:43:20.043Z,1750272200.043 [Default:CheckIn:D] Stopped
2025-06-18T18:43:20.044Z,1750272200.044 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:43:20.444Z,1750272200.444 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.182381 min
2025-06-18T18:43:20.444Z,1750272200.444 [Default:CheckIn:E] Stopped
2025-06-18T18:43:20.445Z,1750272200.445 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:43:20.445Z,1750272200.445 [Default:CheckIn] Stopped
2025-06-18T18:43:20.445Z,1750272200.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:43:20.445Z,1750272200.445 [Default:CheckIn](INFO): Running loop #10
2025-06-18T18:43:20.445Z,1750272200.445 [Default:CheckIn] Running Loop=10
2025-06-18T18:43:20.445Z,1750272200.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:43:20.445Z,1750272200.445 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:43:22.471Z,1750272202.471 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184321.00,A,3648.13735,N,12147.21380,W,0.039,20.59,180625,,,D*4B
2025-06-18T18:43:22.474Z,1750272202.474 [NAL9602](INFO): GPS fix at 20250618T184321: (36.802289, -121.786897)
2025-06-18T18:43:22.484Z,1750272202.484 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:43:22.484Z,1750272202.484 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:43:30.404Z,1750272210.404 [DataOverHttps](INFO): Sending 89 bytes from file Logs/20250618T172731/Courier0034.lzma
2025-06-18T18:43:31.406Z,1750272211.406 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0034.lzma.bak
2025-06-18T18:43:31.406Z,1750272211.406 [DataOverHttps](INFO): SBD MOMSN=25226678
2025-06-18T18:43:34.198Z,1750272214.198 [NAL9602](INFO): SBD MO Status=2, MOMSN=21751, MT Status=2, MTMSN=0
2025-06-18T18:43:34.198Z,1750272214.198 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T18:43:45.491Z,1750272225.491 [NAL9602](INFO): SBD MO Status=0, MOMSN=21751, MT Status=0, MTMSN=0
2025-06-18T18:43:45.491Z,1750272225.491 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:43:49.472Z,1750272229.472 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250618T172731/Express0035.lzma
2025-06-18T18:43:50.474Z,1750272230.474 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0035.lzma.bak
2025-06-18T18:43:50.474Z,1750272230.474 [DataOverHttps](INFO): SBD MOMSN=25226681
2025-06-18T18:43:52.375Z,1750272232.375 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:43:52.375Z,1750272232.375 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:43:52.375Z,1750272232.375 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:44:16.192Z,1750272256.192 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:48:52.960Z,1750272532.960 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:48:52.960Z,1750272532.960 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:48:52.960Z,1750272532.960 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:48:52.960Z,1750272532.960 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:48:53.375Z,1750272533.375 [Default:CheckIn:D] Stopped
2025-06-18T18:48:53.375Z,1750272533.375 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:48:53.780Z,1750272533.780 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.737907 min
2025-06-18T18:48:53.780Z,1750272533.780 [Default:CheckIn:E] Stopped
2025-06-18T18:48:53.781Z,1750272533.781 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:48:53.781Z,1750272533.781 [Default:CheckIn] Stopped
2025-06-18T18:48:53.781Z,1750272533.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:48:53.781Z,1750272533.781 [Default:CheckIn](INFO): Running loop #11
2025-06-18T18:48:53.781Z,1750272533.781 [Default:CheckIn] Running Loop=11
2025-06-18T18:48:53.781Z,1750272533.781 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:48:53.781Z,1750272533.781 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:48:55.780Z,1750272535.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184855.00,A,3648.13691,N,12147.22006,W,0.019,20.59,180625,,,D*40
2025-06-18T18:48:55.782Z,1750272535.782 [NAL9602](INFO): GPS fix at 20250618T184855: (36.802282, -121.787001)
2025-06-18T18:48:55.809Z,1750272535.809 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:48:55.809Z,1750272535.809 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:49:03.140Z,1750272543.140 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0037.lzma
2025-06-18T18:49:04.142Z,1750272544.142 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0037.lzma.bak
2025-06-18T18:49:04.142Z,1750272544.142 [DataOverHttps](INFO): SBD MOMSN=25226691
2025-06-18T18:49:15.566Z,1750272555.566 [NAL9602](INFO): SBD MO Status=0, MOMSN=21752, MT Status=0, MTMSN=0
2025-06-18T18:49:15.566Z,1750272555.566 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:49:20.072Z,1750272560.072 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250618T172731/Express0038.lzma
2025-06-18T18:49:21.074Z,1750272561.074 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0038.lzma.bak
2025-06-18T18:49:21.074Z,1750272561.074 [DataOverHttps](INFO): SBD MOMSN=25226696
2025-06-18T18:49:22.855Z,1750272562.855 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:49:22.855Z,1750272562.855 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:49:22.855Z,1750272562.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:49:46.294Z,1750272586.294 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:54:23.426Z,1750272863.426 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:54:23.426Z,1750272863.426 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:54:23.426Z,1750272863.426 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:54:23.427Z,1750272863.427 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:54:23.832Z,1750272863.832 [Default:CheckIn:D] Stopped
2025-06-18T18:54:23.832Z,1750272863.832 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:54:24.251Z,1750272864.251 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.245524 min
2025-06-18T18:54:24.251Z,1750272864.251 [Default:CheckIn:E] Stopped
2025-06-18T18:54:24.252Z,1750272864.252 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:54:24.252Z,1750272864.252 [Default:CheckIn] Stopped
2025-06-18T18:54:24.252Z,1750272864.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:54:24.252Z,1750272864.252 [Default:CheckIn](INFO): Running loop #12
2025-06-18T18:54:24.252Z,1750272864.252 [Default:CheckIn] Running Loop=12
2025-06-18T18:54:24.252Z,1750272864.252 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:54:24.252Z,1750272864.252 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:54:26.242Z,1750272866.242 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185425.00,A,3648.13490,N,12147.21686,W,0.019,20.59,180625,,,D*44
2025-06-18T18:54:26.244Z,1750272866.244 [NAL9602](INFO): GPS fix at 20250618T185425: (36.802248, -121.786948)
2025-06-18T18:54:26.255Z,1750272866.255 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:54:26.255Z,1750272866.255 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T18:54:35.648Z,1750272875.648 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0040.lzma
2025-06-18T18:54:36.650Z,1750272876.650 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0040.lzma.bak
2025-06-18T18:54:36.650Z,1750272876.650 [DataOverHttps](INFO): SBD MOMSN=25226708
2025-06-18T18:54:36.762Z,1750272876.762 [NAL9602](INFO): SBD MO Status=0, MOMSN=21753, MT Status=0, MTMSN=0
2025-06-18T18:54:36.762Z,1750272876.762 [NAL9602](INFO): No messages in MT queue
2025-06-18T18:54:52.664Z,1750272892.664 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250618T172731/Express0041.lzma
2025-06-18T18:54:53.666Z,1750272893.666 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0041.lzma.bak
2025-06-18T18:54:53.666Z,1750272893.666 [DataOverHttps](INFO): SBD MOMSN=25226711
2025-06-18T18:54:55.355Z,1750272895.355 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T18:54:55.355Z,1750272895.355 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T18:54:55.355Z,1750272895.355 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T18:55:07.461Z,1750272907.461 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T18:59:55.969Z,1750273195.969 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T18:59:55.969Z,1750273195.969 [Default:CheckIn:C.Wait] Stopped
2025-06-18T18:59:55.969Z,1750273195.969 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T18:59:55.969Z,1750273195.969 [Default:CheckIn:D] Running Loop=1
2025-06-18T18:59:56.384Z,1750273196.384 [Default:CheckIn:D] Stopped
2025-06-18T18:59:56.384Z,1750273196.384 [Default:CheckIn:E] Running Loop=1
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.788045 min
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn:E] Stopped
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn] Stopped
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn](INFO): Running loop #13
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn] Running Loop=13
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T18:59:56.771Z,1750273196.771 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T18:59:58.784Z,1750273198.784 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185958.00,A,3648.14009,N,12147.21068,W,0.019,0.00,180625,,,D*78
2025-06-18T18:59:58.786Z,1750273198.786 [NAL9602](INFO): GPS fix at 20250618T185958: (36.802335, -121.786845)
2025-06-18T18:59:58.797Z,1750273198.797 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T18:59:58.797Z,1750273198.797 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:00:06.412Z,1750273206.412 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0043.lzma
2025-06-18T19:00:07.414Z,1750273207.414 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0043.lzma.bak
2025-06-18T19:00:07.414Z,1750273207.414 [DataOverHttps](INFO): SBD MOMSN=25226722
2025-06-18T19:00:23.492Z,1750273223.492 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250618T172731/Express0044.lzma
2025-06-18T19:00:24.494Z,1750273224.494 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0044.lzma.bak
2025-06-18T19:00:24.494Z,1750273224.494 [DataOverHttps](INFO): SBD MOMSN=25226725
2025-06-18T19:00:26.274Z,1750273226.274 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:00:26.274Z,1750273226.274 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:00:26.274Z,1750273226.274 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:03:17.176Z,1750273397.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=21754, MT Status=2, MTMSN=0
2025-06-18T19:03:17.176Z,1750273397.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:03:34.644Z,1750273414.644 [NAL9602](INFO): SBD MO Status=2, MOMSN=21754, MT Status=2, MTMSN=0
2025-06-18T19:03:34.645Z,1750273414.645 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:04:02.025Z,1750273442.025 [NAL9602](INFO): SBD MO Status=2, MOMSN=21754, MT Status=2, MTMSN=0
2025-06-18T19:04:02.025Z,1750273442.025 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:04:17.374Z,1750273457.374 [NAL9602](INFO): SBD MO Status=2, MOMSN=21754, MT Status=2, MTMSN=0
2025-06-18T19:04:17.374Z,1750273457.374 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:05:02.251Z,1750273502.251 [NAL9602](INFO): SBD MO Status=2, MOMSN=21754, MT Status=2, MTMSN=0
2025-06-18T19:05:02.251Z,1750273502.251 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:05:02.646Z,1750273502.646 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-18T19:05:26.901Z,1750273526.901 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:05:26.901Z,1750273526.901 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:05:26.901Z,1750273526.901 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:05:26.901Z,1750273526.901 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:05:27.298Z,1750273527.298 [Default:CheckIn:D] Stopped
2025-06-18T19:05:27.298Z,1750273527.298 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:05:27.700Z,1750273527.700 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.303288 min
2025-06-18T19:05:27.700Z,1750273527.700 [Default:CheckIn:E] Stopped
2025-06-18T19:05:27.700Z,1750273527.700 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:05:27.700Z,1750273527.700 [Default:CheckIn] Stopped
2025-06-18T19:05:27.700Z,1750273527.700 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:05:27.700Z,1750273527.700 [Default:CheckIn](INFO): Running loop #14
2025-06-18T19:05:27.700Z,1750273527.700 [Default:CheckIn] Running Loop=14
2025-06-18T19:05:27.701Z,1750273527.701 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:05:27.701Z,1750273527.701 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:05:29.713Z,1750273529.713 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190528.00,A,3648.14152,N,12147.21432,W,0.039,0.00,180625,,,D*71
2025-06-18T19:05:29.715Z,1750273529.715 [NAL9602](INFO): GPS fix at 20250618T190528: (36.802359, -121.786905)
2025-06-18T19:05:29.726Z,1750273529.726 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:05:29.726Z,1750273529.726 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:05:39.052Z,1750273539.052 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250618T172731/Courier0046.lzma
2025-06-18T19:05:40.054Z,1750273540.054 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0046.lzma.bak
2025-06-18T19:05:40.054Z,1750273540.054 [DataOverHttps](INFO): SBD MOMSN=25226740
2025-06-18T19:05:56.068Z,1750273556.068 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20250618T172731/Express0047.lzma
2025-06-18T19:05:57.070Z,1750273557.070 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0047.lzma.bak
2025-06-18T19:05:57.070Z,1750273557.070 [DataOverHttps](INFO): SBD MOMSN=25226743
2025-06-18T19:05:58.827Z,1750273558.827 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:05:58.827Z,1750273558.827 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:05:58.827Z,1750273558.827 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:06:02.450Z,1750273562.450 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:10:59.421Z,1750273859.421 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:10:59.421Z,1750273859.421 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:10:59.421Z,1750273859.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:10:59.422Z,1750273859.422 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:10:59.821Z,1750273859.821 [Default:CheckIn:D] Stopped
2025-06-18T19:10:59.821Z,1750273859.821 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:11:00.219Z,1750273860.219 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.845345 min
2025-06-18T19:11:00.219Z,1750273860.219 [Default:CheckIn:E] Stopped
2025-06-18T19:11:00.219Z,1750273860.219 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:11:00.219Z,1750273860.219 [Default:CheckIn] Stopped
2025-06-18T19:11:00.219Z,1750273860.219 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:11:00.220Z,1750273860.220 [Default:CheckIn](INFO): Running loop #15
2025-06-18T19:11:00.220Z,1750273860.220 [Default:CheckIn] Running Loop=15
2025-06-18T19:11:00.236Z,1750273860.236 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:11:00.236Z,1750273860.236 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:11:02.230Z,1750273862.230 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191101.00,A,3648.13803,N,12147.21990,W,0.019,0.00,180625,,,D*72
2025-06-18T19:11:02.233Z,1750273862.233 [NAL9602](INFO): GPS fix at 20250618T191101: (36.802301, -121.786998)
2025-06-18T19:11:02.243Z,1750273862.243 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:11:02.243Z,1750273862.243 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:11:09.400Z,1750273869.400 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0049.lzma
2025-06-18T19:11:10.402Z,1750273870.402 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0049.lzma.bak
2025-06-18T19:11:10.402Z,1750273870.402 [DataOverHttps](INFO): SBD MOMSN=25226769
2025-06-18T19:11:26.300Z,1750273886.300 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250618T172731/Express0050.lzma
2025-06-18T19:11:27.302Z,1750273887.302 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0050.lzma.bak
2025-06-18T19:11:27.302Z,1750273887.302 [DataOverHttps](INFO): SBD MOMSN=25226772
2025-06-18T19:11:28.991Z,1750273888.991 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:11:28.991Z,1750273888.991 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:11:28.991Z,1750273888.991 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:13:22.187Z,1750274002.187 [NAL9602](INFO): SBD MO Status=2, MOMSN=21754, MT Status=2, MTMSN=0
2025-06-18T19:13:22.187Z,1750274002.187 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:16:04.577Z,1750274164.577 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-18T19:16:29.632Z,1750274189.632 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:16:29.632Z,1750274189.632 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:16:29.632Z,1750274189.632 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:16:29.632Z,1750274189.632 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:16:30.050Z,1750274190.050 [Default:CheckIn:D] Stopped
2025-06-18T19:16:30.050Z,1750274190.050 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:16:30.455Z,1750274190.455 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.349154 min
2025-06-18T19:16:30.455Z,1750274190.455 [Default:CheckIn:E] Stopped
2025-06-18T19:16:30.456Z,1750274190.456 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:16:30.456Z,1750274190.456 [Default:CheckIn] Stopped
2025-06-18T19:16:30.456Z,1750274190.456 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:16:30.456Z,1750274190.456 [Default:CheckIn](INFO): Running loop #16
2025-06-18T19:16:30.456Z,1750274190.456 [Default:CheckIn] Running Loop=16
2025-06-18T19:16:30.456Z,1750274190.456 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:16:30.456Z,1750274190.456 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:16:32.469Z,1750274192.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191631.00,A,3648.13531,N,12147.21259,W,0.000,0.00,180625,,,D*7C
2025-06-18T19:16:32.497Z,1750274192.497 [NAL9602](INFO): GPS fix at 20250618T191631: (36.802255, -121.786877)
2025-06-18T19:16:32.547Z,1750274192.547 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:16:32.547Z,1750274192.547 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:16:40.701Z,1750274200.701 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0052.lzma
2025-06-18T19:16:41.702Z,1750274201.702 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0052.lzma.bak
2025-06-18T19:16:41.702Z,1750274201.702 [DataOverHttps](INFO): SBD MOMSN=25226783
2025-06-18T19:16:57.668Z,1750274217.668 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20250618T172731/Express0053.lzma
2025-06-18T19:16:58.670Z,1750274218.670 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0053.lzma.bak
2025-06-18T19:16:58.670Z,1750274218.670 [DataOverHttps](INFO): SBD MOMSN=25226789
2025-06-18T19:17:00.398Z,1750274220.398 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:17:00.398Z,1750274220.398 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:17:00.399Z,1750274220.399 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:17:04.453Z,1750274224.453 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:22:00.996Z,1750274520.996 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:22:00.996Z,1750274520.996 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:22:00.996Z,1750274520.996 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:22:00.996Z,1750274520.996 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:22:01.378Z,1750274521.378 [Default:CheckIn:D] Stopped
2025-06-18T19:22:01.378Z,1750274521.378 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:22:01.780Z,1750274521.780 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.871289 min
2025-06-18T19:22:01.780Z,1750274521.780 [Default:CheckIn:E] Stopped
2025-06-18T19:22:01.780Z,1750274521.780 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:22:01.780Z,1750274521.780 [Default:CheckIn] Stopped
2025-06-18T19:22:01.781Z,1750274521.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:22:01.781Z,1750274521.781 [Default:CheckIn](INFO): Running loop #17
2025-06-18T19:22:01.781Z,1750274521.781 [Default:CheckIn] Running Loop=17
2025-06-18T19:22:01.781Z,1750274521.781 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:22:01.781Z,1750274521.781 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:22:03.795Z,1750274523.795 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192203.00,A,3648.13395,N,12147.21384,W,0.039,0.00,180625,,,D*79
2025-06-18T19:22:03.798Z,1750274523.798 [NAL9602](INFO): GPS fix at 20250618T192203: (36.802233, -121.786897)
2025-06-18T19:22:03.825Z,1750274523.825 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:22:03.825Z,1750274523.825 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:22:11.134Z,1750274531.134 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0055.lzma
2025-06-18T19:22:12.134Z,1750274532.134 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0055.lzma.bak
2025-06-18T19:22:12.134Z,1750274532.134 [DataOverHttps](INFO): SBD MOMSN=25226801
2025-06-18T19:22:28.148Z,1750274548.148 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20250618T172731/Express0056.lzma
2025-06-18T19:22:29.150Z,1750274549.150 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0056.lzma.bak
2025-06-18T19:22:29.150Z,1750274549.150 [DataOverHttps](INFO): SBD MOMSN=25226807
2025-06-18T19:22:30.883Z,1750274550.883 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:22:30.884Z,1750274550.884 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:22:30.884Z,1750274550.884 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:22:34.554Z,1750274554.554 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-06-18T19:22:34.645Z,1750274554.645 [NAL9602](ERROR): received:
+CSQ:0
OK754, 2, 0, 0, 0
OK
2025-06-18T19:25:32.694Z,1750274732.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=21754, MT Status=2, MTMSN=0
2025-06-18T19:25:32.694Z,1750274732.694 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:26:59.558Z,1750274819.558 [NAL9602](INFO): SBD MO Status=0, MOMSN=21754, MT Status=0, MTMSN=0
2025-06-18T19:26:59.558Z,1750274819.558 [NAL9602](INFO): No messages in MT queue
2025-06-18T19:27:30.250Z,1750274850.250 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:27:31.485Z,1750274851.485 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:27:31.486Z,1750274851.486 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:27:31.486Z,1750274851.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:27:31.486Z,1750274851.486 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:27:31.881Z,1750274851.881 [Default:CheckIn:D] Stopped
2025-06-18T19:27:31.881Z,1750274851.881 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.379671 min
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn:E] Stopped
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn] Stopped
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn](INFO): Running loop #18
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn] Running Loop=18
2025-06-18T19:27:32.301Z,1750274852.301 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:27:32.302Z,1750274852.302 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:27:34.319Z,1750274854.319 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192733.00,A,3648.13000,N,12147.20679,W,0.039,0.00,180625,,,D*76
2025-06-18T19:27:34.321Z,1750274854.321 [NAL9602](INFO): GPS fix at 20250618T192733: (36.802167, -121.786780)
2025-06-18T19:27:34.331Z,1750274854.331 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:27:34.331Z,1750274854.331 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:27:42.032Z,1750274862.032 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0058.lzma
2025-06-18T19:27:43.034Z,1750274863.034 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0058.lzma.bak
2025-06-18T19:27:43.034Z,1750274863.034 [DataOverHttps](INFO): SBD MOMSN=25226817
2025-06-18T19:27:59.436Z,1750274879.436 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250618T172731/Express0059.lzma
2025-06-18T19:28:00.438Z,1750274880.438 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0059.lzma.bak
2025-06-18T19:28:00.438Z,1750274880.438 [DataOverHttps](INFO): SBD MOMSN=25226820
2025-06-18T19:28:02.287Z,1750274882.287 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:28:02.287Z,1750274882.287 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:28:02.287Z,1750274882.287 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:28:03.508Z,1750274883.508 [NAL9602](INFO): SBD MO Status=0, MOMSN=21755, MT Status=0, MTMSN=0
2025-06-18T19:28:03.508Z,1750274883.508 [NAL9602](INFO): No messages in MT queue
2025-06-18T19:28:34.240Z,1750274914.240 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:33:02.858Z,1750275182.858 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:33:02.858Z,1750275182.858 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:33:02.858Z,1750275182.858 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:33:02.858Z,1750275182.858 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:33:03.262Z,1750275183.262 [Default:CheckIn:D] Stopped
2025-06-18T19:33:03.262Z,1750275183.262 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:33:03.676Z,1750275183.676 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.902686 min
2025-06-18T19:33:03.676Z,1750275183.676 [Default:CheckIn:E] Stopped
2025-06-18T19:33:03.676Z,1750275183.676 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:33:03.676Z,1750275183.676 [Default:CheckIn] Stopped
2025-06-18T19:33:03.676Z,1750275183.676 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:33:03.676Z,1750275183.676 [Default:CheckIn](INFO): Running loop #19
2025-06-18T19:33:03.676Z,1750275183.676 [Default:CheckIn] Running Loop=19
2025-06-18T19:33:03.677Z,1750275183.677 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:33:03.677Z,1750275183.677 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:33:05.685Z,1750275185.685 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193304.00,A,3648.12731,N,12147.21148,W,0.019,0.00,180625,,,D*75
2025-06-18T19:33:05.687Z,1750275185.687 [NAL9602](INFO): GPS fix at 20250618T193304: (36.802122, -121.786858)
2025-06-18T19:33:05.698Z,1750275185.698 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:33:05.698Z,1750275185.698 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:33:12.972Z,1750275192.972 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250618T172731/Courier0061.lzma
2025-06-18T19:33:13.983Z,1750275193.983 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0061.lzma.bak
2025-06-18T19:33:13.986Z,1750275193.986 [DataOverHttps](INFO): SBD MOMSN=25226832
2025-06-18T19:33:30.080Z,1750275210.080 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250618T172731/Express0062.lzma
2025-06-18T19:33:31.082Z,1750275211.082 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0062.lzma.bak
2025-06-18T19:33:31.082Z,1750275211.082 [DataOverHttps](INFO): SBD MOMSN=25226835
2025-06-18T19:33:33.219Z,1750275213.219 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:33:33.219Z,1750275213.219 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:33:33.219Z,1750275213.219 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:34:24.872Z,1750275264.872 [NAL9602](INFO): SBD MO Status=0, MOMSN=21756, MT Status=0, MTMSN=0
2025-06-18T19:34:24.872Z,1750275264.872 [NAL9602](INFO): No messages in MT queue
2025-06-18T19:34:55.590Z,1750275295.590 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:38:33.769Z,1750275513.769 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:38:33.769Z,1750275513.769 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:38:33.769Z,1750275513.769 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:38:33.769Z,1750275513.769 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:38:34.174Z,1750275514.174 [Default:CheckIn:D] Stopped
2025-06-18T19:38:34.174Z,1750275514.174 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.417879 min
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn:E] Stopped
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn] Stopped
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn](INFO): Running loop #20
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn] Running Loop=20
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:38:34.569Z,1750275514.569 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:38:36.562Z,1750275516.562 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193835.00,A,3648.13288,N,12147.21897,W,0.019,0.00,180625,,,D*71
2025-06-18T19:38:36.564Z,1750275516.564 [NAL9602](INFO): GPS fix at 20250618T193835: (36.802215, -121.786983)
2025-06-18T19:38:36.595Z,1750275516.595 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:38:36.595Z,1750275516.595 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:38:44.172Z,1750275524.172 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0064.lzma
2025-06-18T19:38:45.174Z,1750275525.174 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0064.lzma.bak
2025-06-18T19:38:45.174Z,1750275525.174 [DataOverHttps](INFO): SBD MOMSN=25226848
2025-06-18T19:39:01.300Z,1750275541.300 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20250618T172731/Express0065.lzma
2025-06-18T19:39:02.302Z,1750275542.302 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0065.lzma.bak
2025-06-18T19:39:02.302Z,1750275542.302 [DataOverHttps](INFO): SBD MOMSN=25226851
2025-06-18T19:39:04.507Z,1750275544.507 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:39:04.507Z,1750275544.507 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:39:04.507Z,1750275544.507 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:39:19.392Z,1750275559.392 [NAL9602](INFO): SBD MO Status=2, MOMSN=21757, MT Status=2, MTMSN=0
2025-06-18T19:39:19.393Z,1750275559.393 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:39:39.183Z,1750275579.183 [NAL9602](INFO): SBD MO Status=0, MOMSN=21757, MT Status=0, MTMSN=0
2025-06-18T19:39:39.183Z,1750275579.183 [NAL9602](INFO): No messages in MT queue
2025-06-18T19:40:09.889Z,1750275609.889 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:41:19.380Z,1750275679.380 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00000000000000,35.00,A
2025-06-18T19:41:19.380Z,1750275679.380 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.00,A
2025-06-18T19:44:05.033Z,1750275845.033 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:44:05.033Z,1750275845.033 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:44:05.034Z,1750275845.034 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:44:05.034Z,1750275845.034 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:44:05.447Z,1750275845.447 [Default:CheckIn:D] Stopped
2025-06-18T19:44:05.447Z,1750275845.447 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:44:05.870Z,1750275845.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.939103 min
2025-06-18T19:44:05.870Z,1750275845.870 [Default:CheckIn:E] Stopped
2025-06-18T19:44:05.870Z,1750275845.870 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:44:05.871Z,1750275845.871 [Default:CheckIn] Stopped
2025-06-18T19:44:05.871Z,1750275845.871 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:44:05.871Z,1750275845.871 [Default:CheckIn](INFO): Running loop #21
2025-06-18T19:44:05.871Z,1750275845.871 [Default:CheckIn] Running Loop=21
2025-06-18T19:44:05.871Z,1750275845.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:44:05.871Z,1750275845.871 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:44:07.848Z,1750275847.848 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194407.00,A,3648.14042,N,12147.21506,W,0.019,125.10,180625,,,D*7A
2025-06-18T19:44:07.850Z,1750275847.850 [NAL9602](INFO): GPS fix at 20250618T194407: (36.802340, -121.786918)
2025-06-18T19:44:07.861Z,1750275847.861 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:44:07.861Z,1750275847.861 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:44:15.616Z,1750275855.616 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0067.lzma
2025-06-18T19:44:16.618Z,1750275856.618 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0067.lzma.bak
2025-06-18T19:44:16.618Z,1750275856.618 [DataOverHttps](INFO): SBD MOMSN=25226863
2025-06-18T19:44:33.190Z,1750275873.190 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250618T172731/Express0068.lzma
2025-06-18T19:44:34.190Z,1750275874.190 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0068.lzma.bak
2025-06-18T19:44:34.191Z,1750275874.191 [DataOverHttps](INFO): SBD MOMSN=25226866
2025-06-18T19:44:35.791Z,1750275875.791 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:44:35.791Z,1750275875.791 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:44:35.791Z,1750275875.791 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:45:18.146Z,1750275918.146 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-06-18T19:45:46.442Z,1750275946.442 [NAL9602](INFO): SBD MO Status=2, MOMSN=21758, MT Status=2, MTMSN=0
2025-06-18T19:45:46.442Z,1750275946.442 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-18T19:46:04.199Z,1750275964.199 [NAL9602](INFO): SBD MO Status=0, MOMSN=21758, MT Status=0, MTMSN=0
2025-06-18T19:46:04.200Z,1750275964.200 [NAL9602](INFO): No messages in MT queue
2025-06-18T19:46:34.910Z,1750275994.910 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:49:17.003Z,1750276157.003 [BPC1](FAULT): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-06-18T19:49:17.004Z,1750276157.004 [BPC1](FAULT): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-06-18T19:49:17.005Z,1750276157.005 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2025-06-18T19:49:17.007Z,1750276157.007 [BPC1](INFO): Received data from all battery sticks.
2025-06-18T19:49:36.418Z,1750276176.418 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:49:36.418Z,1750276176.418 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:49:36.418Z,1750276176.418 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:49:36.418Z,1750276176.418 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:49:36.807Z,1750276176.807 [Default:CheckIn:D] Stopped
2025-06-18T19:49:36.807Z,1750276176.807 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:49:37.207Z,1750276177.207 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.461768 min
2025-06-18T19:49:37.207Z,1750276177.207 [Default:CheckIn:E] Stopped
2025-06-18T19:49:37.207Z,1750276177.207 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:49:37.207Z,1750276177.207 [Default:CheckIn] Stopped
2025-06-18T19:49:37.207Z,1750276177.207 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:49:37.208Z,1750276177.208 [Default:CheckIn](INFO): Running loop #22
2025-06-18T19:49:37.208Z,1750276177.208 [Default:CheckIn] Running Loop=22
2025-06-18T19:49:37.208Z,1750276177.208 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:49:37.208Z,1750276177.208 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:49:39.223Z,1750276179.223 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194938.00,A,3648.18596,N,12147.18059,W,3.810,40.11,180625,,,D*4F
2025-06-18T19:49:39.226Z,1750276179.226 [NAL9602](INFO): GPS fix at 20250618T194938: (36.803099, -121.786343)
2025-06-18T19:49:39.236Z,1750276179.236 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:49:39.236Z,1750276179.236 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:49:47.144Z,1750276187.144 [DataOverHttps](INFO): Sending 87 bytes from file Logs/20250618T172731/Courier0070.lzma
2025-06-18T19:49:48.146Z,1750276188.146 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0070.lzma.bak
2025-06-18T19:49:48.146Z,1750276188.146 [DataOverHttps](INFO): SBD MOMSN=25226878
2025-06-18T19:49:51.743Z,1750276191.743 [NAL9602](INFO): SBD MO Status=0, MOMSN=21759, MT Status=0, MTMSN=0
2025-06-18T19:49:51.743Z,1750276191.743 [NAL9602](INFO): No messages in MT queue
2025-06-18T19:50:04.344Z,1750276204.344 [DataOverHttps](INFO): Sending 295 bytes from file Logs/20250618T172731/Express0071.lzma
2025-06-18T19:50:05.346Z,1750276205.346 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0071.lzma.bak
2025-06-18T19:50:05.346Z,1750276205.346 [DataOverHttps](INFO): SBD MOMSN=25226882
2025-06-18T19:50:07.119Z,1750276207.119 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:50:07.119Z,1750276207.119 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:50:07.119Z,1750276207.119 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:50:22.445Z,1750276222.445 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T19:53:44.853Z,1750276424.853 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2025-06-18T19:55:07.683Z,1750276507.683 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T19:55:07.683Z,1750276507.683 [Default:CheckIn:C.Wait] Stopped
2025-06-18T19:55:07.683Z,1750276507.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T19:55:07.683Z,1750276507.683 [Default:CheckIn:D] Running Loop=1
2025-06-18T19:55:08.084Z,1750276508.084 [Default:CheckIn:D] Stopped
2025-06-18T19:55:08.084Z,1750276508.084 [Default:CheckIn:E] Running Loop=1
2025-06-18T19:55:08.494Z,1750276508.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.983057 min
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn:E] Stopped
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn] Stopped
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn](INFO): Running loop #23
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn] Running Loop=23
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T19:55:08.495Z,1750276508.495 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T19:55:10.502Z,1750276510.502 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195509.00,A,3648.46013,N,12147.32320,W,6.784,234.40,180625,,,D*74
2025-06-18T19:55:10.504Z,1750276510.504 [NAL9602](INFO): GPS fix at 20250618T195509: (36.807669, -121.788720)
2025-06-18T19:55:10.532Z,1750276510.532 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T19:55:10.532Z,1750276510.532 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T19:55:18.428Z,1750276518.428 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250618T172731/Courier0073.lzma
2025-06-18T19:55:19.430Z,1750276519.430 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0073.lzma.bak
2025-06-18T19:55:19.430Z,1750276519.430 [DataOverHttps](INFO): SBD MOMSN=25226894
2025-06-18T19:55:38.408Z,1750276538.408 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20250618T172731/Express0074.lzma
2025-06-18T19:55:39.410Z,1750276539.410 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0074.lzma.bak
2025-06-18T19:55:39.410Z,1750276539.410 [DataOverHttps](INFO): SBD MOMSN=25226897
2025-06-18T19:55:40.848Z,1750276540.848 [DVL_micro](ERROR): only read 2 of 4 data items for beam range. Device response is::RD,+9999.99,+999999.99
2025-06-18T19:55:40.852Z,1750276540.852 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+999999.99
2025-06-18T19:55:41.240Z,1750276541.240 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T19:55:41.240Z,1750276541.240 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T19:55:41.240Z,1750276541.240 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T19:56:13.531Z,1750276573.531 [NAL9602](INFO): SBD MO Status=0, MOMSN=21760, MT Status=0, MTMSN=0
2025-06-18T19:56:13.531Z,1750276573.531 [NAL9602](INFO): No messages in MT queue
2025-06-18T19:56:44.257Z,1750276604.257 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T20:00:41.799Z,1750276841.799 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T20:00:41.799Z,1750276841.799 [Default:CheckIn:C.Wait] Stopped
2025-06-18T20:00:41.799Z,1750276841.799 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T20:00:41.799Z,1750276841.799 [Default:CheckIn:D] Running Loop=1
2025-06-18T20:00:42.218Z,1750276842.218 [Default:CheckIn:D] Stopped
2025-06-18T20:00:42.218Z,1750276842.218 [Default:CheckIn:E] Running Loop=1
2025-06-18T20:00:42.618Z,1750276842.618 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.551953 min
2025-06-18T20:00:42.618Z,1750276842.618 [Default:CheckIn:E] Stopped
2025-06-18T20:00:42.618Z,1750276842.618 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T20:00:42.618Z,1750276842.618 [Default:CheckIn] Stopped
2025-06-18T20:00:42.619Z,1750276842.619 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T20:00:42.619Z,1750276842.619 [Default:CheckIn](INFO): Running loop #24
2025-06-18T20:00:42.619Z,1750276842.619 [Default:CheckIn] Running Loop=24
2025-06-18T20:00:42.619Z,1750276842.619 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T20:00:42.619Z,1750276842.619 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T20:00:44.619Z,1750276844.619 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200043.00,A,3648.07585,N,12148.30678,W,9.603,243.96,180625,,,D*70
2025-06-18T20:00:44.622Z,1750276844.622 [NAL9602](INFO): GPS fix at 20250618T200043: (36.801264, -121.805113)
2025-06-18T20:00:44.649Z,1750276844.649 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T20:00:44.649Z,1750276844.649 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T20:00:53.092Z,1750276853.092 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250618T172731/Courier0076.lzma
2025-06-18T20:00:54.094Z,1750276854.094 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0076.lzma.bak
2025-06-18T20:00:54.094Z,1750276854.094 [DataOverHttps](INFO): SBD MOMSN=25226907
2025-06-18T20:01:00.371Z,1750276860.371 [NAL9602](INFO): SBD MO Status=0, MOMSN=21761, MT Status=0, MTMSN=0
2025-06-18T20:01:00.371Z,1750276860.371 [NAL9602](INFO): No messages in MT queue
2025-06-18T20:01:10.978Z,1750276870.978 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20250618T172731/Express0077.lzma
2025-06-18T20:01:11.978Z,1750276871.978 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0077.lzma.bak
2025-06-18T20:01:11.978Z,1750276871.978 [DataOverHttps](INFO): SBD MOMSN=25226910
2025-06-18T20:01:13.730Z,1750276873.730 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T20:01:13.730Z,1750276873.730 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T20:01:13.731Z,1750276873.731 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T20:01:31.080Z,1750276891.080 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T20:06:14.308Z,1750277174.308 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T20:06:14.308Z,1750277174.308 [Default:CheckIn:C.Wait] Stopped
2025-06-18T20:06:14.308Z,1750277174.308 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T20:06:14.308Z,1750277174.308 [Default:CheckIn:D] Running Loop=1
2025-06-18T20:06:14.717Z,1750277174.717 [Default:CheckIn:D] Stopped
2025-06-18T20:06:14.717Z,1750277174.717 [Default:CheckIn:E] Running Loop=1
2025-06-18T20:06:15.114Z,1750277175.114 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.093604 min
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn:E] Stopped
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn] Stopped
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn](INFO): Running loop #25
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn] Running Loop=25
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T20:06:15.115Z,1750277175.115 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T20:06:17.127Z,1750277177.127 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200616.00,A,3647.63922,N,12149.68059,W,10.613,266.73,180625,,,D*46
2025-06-18T20:06:17.129Z,1750277177.129 [NAL9602](INFO): GPS fix at 20250618T200616: (36.793987, -121.828010)
2025-06-18T20:06:17.139Z,1750277177.139 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T20:06:17.139Z,1750277177.139 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T20:06:24.324Z,1750277184.324 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250618T172731/Courier0079.lzma
2025-06-18T20:06:25.326Z,1750277185.326 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0079.lzma.bak
2025-06-18T20:06:25.326Z,1750277185.326 [DataOverHttps](INFO): SBD MOMSN=25226920
2025-06-18T20:06:26.130Z,1750277186.130 [NAL9602](INFO): SBD MO Status=0, MOMSN=21762, MT Status=0, MTMSN=0
2025-06-18T20:06:26.130Z,1750277186.130 [NAL9602](INFO): No messages in MT queue
2025-06-18T20:06:42.728Z,1750277202.728 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20250618T172731/Express0080.lzma
2025-06-18T20:06:43.730Z,1750277203.730 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Express0080.lzma.bak
2025-06-18T20:06:43.730Z,1750277203.730 [DataOverHttps](INFO): SBD MOMSN=25226923
2025-06-18T20:06:45.504Z,1750277205.504 [Default:CheckIn:Read_Iridium] Stopped
2025-06-18T20:06:45.504Z,1750277205.504 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-18T20:06:45.504Z,1750277205.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-18T20:06:56.800Z,1750277216.800 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-18T20:11:46.077Z,1750277506.077 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-18T20:11:46.077Z,1750277506.077 [Default:CheckIn:C.Wait] Stopped
2025-06-18T20:11:46.077Z,1750277506.077 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-18T20:11:46.077Z,1750277506.077 [Default:CheckIn:D] Running Loop=1
2025-06-18T20:11:46.485Z,1750277506.485 [Default:CheckIn:D] Stopped
2025-06-18T20:11:46.485Z,1750277506.485 [Default:CheckIn:E] Running Loop=1
2025-06-18T20:11:46.883Z,1750277506.883 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.623047 min
2025-06-18T20:11:46.883Z,1750277506.883 [Default:CheckIn:E] Stopped
2025-06-18T20:11:46.883Z,1750277506.883 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-18T20:11:46.883Z,1750277506.883 [Default:CheckIn] Stopped
2025-06-18T20:11:46.883Z,1750277506.883 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-18T20:11:46.884Z,1750277506.884 [Default:CheckIn](INFO): Running loop #26
2025-06-18T20:11:46.884Z,1750277506.884 [Default:CheckIn] Running Loop=26
2025-06-18T20:11:46.884Z,1750277506.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-18T20:11:46.901Z,1750277506.901 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-18T20:11:48.898Z,1750277508.898 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201148.00,A,3647.57795,N,12149.99160,W,1.089,91.82,180625,,,A*4F
2025-06-18T20:11:48.901Z,1750277508.901 [NAL9602](INFO): GPS fix at 20250618T201148: (36.792966, -121.833193)
2025-06-18T20:11:48.911Z,1750277508.911 [Default:CheckIn:Read_GPS] Stopped
2025-06-18T20:11:48.911Z,1750277508.911 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-18T20:11:56.612Z,1750277516.612 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250618T172731/Courier0082.lzma
2025-06-18T20:11:57.614Z,1750277517.614 [DataOverHttps](INFO): Moved sent file to Logs/20250618T172731/Courier0082.lzma.bak
2025-06-18T20:11:57.615Z,1750277517.615 [DataOverHttps](IMPORTANT): SBD MOMSN=25226935, MTMSN=20250618T201156
2025-06-18T20:12:05.188Z,1750277525.188 [DataOverHttps](INFO): Received command: restart logs