2025-05-05T15:53:04.442Z,1746460384.442 [Supervisor](DEBUG): Initializing supervisor.
2025-05-05T15:53:04.447Z,1746460384.447 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-05-05T15:53:04.447Z,1746460384.447 [SyncHandler](INFO): Protected caller Thread ID is 999
2025-05-05T15:53:04.448Z,1746460384.448 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-05-05T15:53:04.449Z,1746460384.449 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-05-05T15:53:04.449Z,1746460384.449 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1000
2025-05-05T15:53:04.453Z,1746460384.453 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-05-05T15:53:04.473Z,1746460384.473 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-05-05T15:53:04.474Z,1746460384.474 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-05-05T15:53:04.474Z,1746460384.474 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1001
2025-05-05T15:53:04.479Z,1746460384.479 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-05-05T15:53:04.480Z,1746460384.480 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-05-05T15:53:04.480Z,1746460384.480 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1002
2025-05-05T15:53:04.482Z,1746460384.482 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-05-05T15:53:04.483Z,1746460384.483 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-05-05T15:53:04.484Z,1746460384.484 [logger ThreadHandler](INFO): Protected caller Thread ID is 1003
2025-05-05T15:53:04.488Z,1746460384.488 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-05-05T15:53:04.488Z,1746460384.488 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-05-05T15:53:04.492Z,1746460384.492 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-05-05T15:53:04.778Z,1746460384.778 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-05-05T15:53:04.780Z,1746460384.780 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-05-05T15:53:04.898Z,1746460384.898 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-05-05T15:53:04.899Z,1746460384.899 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-05-05T15:53:05.006Z,1746460385.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-05-05T15:53:05.007Z,1746460385.007 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-05-05T15:53:05.506Z,1746460385.506 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-05-05T15:53:05.507Z,1746460385.507 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-05-05T15:53:05.869Z,1746460385.869 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-05-05T15:53:05.869Z,1746460385.869 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-05-05T15:53:06.228Z,1746460386.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-05-05T15:53:06.229Z,1746460386.229 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-05-05T15:53:06.429Z,1746460386.429 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-05-05T15:53:06.429Z,1746460386.429 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-05-05T15:53:06.525Z,1746460386.525 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-05-05T15:53:06.646Z,1746460386.646 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-05-05T15:53:07.128Z,1746460387.128 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-05-05T15:53:07.129Z,1746460387.129 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-05-05T15:53:07.430Z,1746460387.430 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-05-05T15:53:07.431Z,1746460387.431 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-05-05T15:53:08.006Z,1746460388.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-05-05T15:53:08.006Z,1746460388.006 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-05-05T15:53:08.784Z,1746460388.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-05-05T15:53:08.785Z,1746460388.785 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-05-05T15:53:09.039Z,1746460389.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-05-05T15:53:09.040Z,1746460389.040 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-05-05T15:53:09.192Z,1746460389.192 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-05-05T15:53:09.194Z,1746460389.194 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-05-05T15:53:10.072Z,1746460390.072 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-05-05T15:53:10.074Z,1746460390.074 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2025-05-05T15:53:10.077Z,1746460390.077 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2025-05-05T15:53:10.175Z,1746460390.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2025-05-05T15:53:10.319Z,1746460390.319 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2025-05-05T15:53:10.599Z,1746460390.599 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-05-05T15:53:10.601Z,1746460390.601 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2025-05-05T15:53:10.737Z,1746460390.737 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2025-05-05T15:53:10.846Z,1746460390.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2025-05-05T15:53:10.951Z,1746460390.951 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2025-05-05T15:53:11.070Z,1746460391.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2025-05-05T15:53:11.167Z,1746460391.167 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2025-05-05T15:53:11.265Z,1746460391.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2025-05-05T15:53:11.367Z,1746460391.367 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2025-05-05T15:53:11.548Z,1746460391.548 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2025-05-05T15:53:11.548Z,1746460391.548 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-05-05T15:53:11.564Z,1746460391.564 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-05-05T15:53:11.636Z,1746460391.636 [DepthRateCalculator] Loaded
2025-05-05T15:53:11.636Z,1746460391.636 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-05-05T15:53:11.641Z,1746460391.641 [PitchRateCalculator] Loaded
2025-05-05T15:53:11.642Z,1746460391.642 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-05-05T15:53:11.652Z,1746460391.652 [SpeedCalculator] Loaded
2025-05-05T15:53:11.652Z,1746460391.652 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-05-05T15:53:11.657Z,1746460391.657 [YawRateCalculator] Loaded
2025-05-05T15:53:11.657Z,1746460391.657 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-05-05T15:53:11.678Z,1746460391.678 [ElevatorOffsetCalculator] Loaded
2025-05-05T15:53:11.679Z,1746460391.679 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-05-05T15:53:11.679Z,1746460391.679 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-05-05T15:53:11.680Z,1746460391.680 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-05-05T15:53:11.728Z,1746460391.728 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-05-05T15:53:11.730Z,1746460391.730 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-05-05T15:53:11.746Z,1746460391.746 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-05-05T15:53:11.746Z,1746460391.746 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-05-05T15:53:12.518Z,1746460392.518 [AHRS_M2] Loaded
2025-05-05T15:53:12.518Z,1746460392.518 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-05-05T15:53:12.771Z,1746460392.771 [BackseatComponent] Loaded
2025-05-05T15:53:12.772Z,1746460392.772 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-05-05T15:53:12.773Z,1746460392.773 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408754E0
2025-05-05T15:53:12.773Z,1746460392.773 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1086
2025-05-05T15:53:12.776Z,1746460392.776 [LcmUniversalReporter] Loaded
2025-05-05T15:53:12.776Z,1746460392.776 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-05-05T15:53:14.233Z,1746460394.233 [BPC1] Loaded
2025-05-05T15:53:14.233Z,1746460394.233 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-05-05T15:53:14.334Z,1746460394.334 [DAT] Loaded
2025-05-05T15:53:14.334Z,1746460394.334 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-05-05T15:53:14.335Z,1746460394.335 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408A54E0
2025-05-05T15:53:14.336Z,1746460394.336 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1087
2025-05-05T15:53:14.432Z,1746460394.432 [DataOverHttps] Loaded
2025-05-05T15:53:14.432Z,1746460394.432 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-05-05T15:53:14.433Z,1746460394.433 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408D54E0
2025-05-05T15:53:14.434Z,1746460394.434 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1088
2025-05-05T15:53:14.456Z,1746460394.456 [Depth_Keller] Loaded
2025-05-05T15:53:14.456Z,1746460394.456 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-05-05T15:53:14.461Z,1746460394.461 [DropWeight] Loaded
2025-05-05T15:53:14.462Z,1746460394.462 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-05-05T15:53:14.483Z,1746460394.483 [MultiRay](INFO): Found secondary power supply at: /dev/loadC7
2025-05-05T15:53:14.483Z,1746460394.483 [MultiRay] Loaded
2025-05-05T15:53:14.483Z,1746460394.483 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2025-05-05T15:53:14.547Z,1746460394.547 [NAL9602] Loaded
2025-05-05T15:53:14.547Z,1746460394.547 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-05-05T15:53:14.577Z,1746460394.577 [Onboard] Loaded
2025-05-05T15:53:14.577Z,1746460394.577 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-05-05T15:53:14.578Z,1746460394.578 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409054E0
2025-05-05T15:53:14.578Z,1746460394.578 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1089
2025-05-05T15:53:14.584Z,1746460394.584 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2025-05-05T15:53:14.598Z,1746460394.598 [PowerOnly] Loaded
2025-05-05T15:53:14.598Z,1746460394.598 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-05-05T15:53:14.611Z,1746460394.611 [Power24vConverter] Loaded
2025-05-05T15:53:14.612Z,1746460394.612 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-05-05T15:53:14.629Z,1746460394.629 [Radio_Surface] Loaded
2025-05-05T15:53:14.629Z,1746460394.629 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-05-05T15:53:14.630Z,1746460394.630 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409354E0
2025-05-05T15:53:14.630Z,1746460394.630 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1090
2025-05-05T15:53:14.631Z,1746460394.631 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-05-05T15:53:14.632Z,1746460394.632 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-05-05T15:53:14.770Z,1746460394.770 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-05-05T15:53:14.770Z,1746460394.770 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-05-05T15:53:14.784Z,1746460394.784 [NavChart] Loaded
2025-05-05T15:53:14.784Z,1746460394.784 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-05-05T15:53:14.790Z,1746460394.790 [UniversalFixResidualReporter] Loaded
2025-05-05T15:53:14.790Z,1746460394.790 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-05-05T15:53:14.790Z,1746460394.790 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-05-05T15:53:14.791Z,1746460394.791 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-05-05T15:53:14.986Z,1746460394.986 [SBIT](DEBUG): Construct Startup Built In Test.
2025-05-05T15:53:15.000Z,1746460395.000 [SBIT] Loaded
2025-05-05T15:53:15.000Z,1746460395.000 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-05-05T15:53:15.003Z,1746460395.003 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-05-05T15:53:15.016Z,1746460395.016 [IBIT] Loaded
2025-05-05T15:53:15.016Z,1746460395.016 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-05-05T15:53:15.021Z,1746460395.021 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-05-05T15:53:15.101Z,1746460395.101 [CBIT] Loaded
2025-05-05T15:53:15.101Z,1746460395.101 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-05-05T15:53:15.132Z,1746460395.132 [GFScanner] Loaded
2025-05-05T15:53:15.132Z,1746460395.132 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-05-05T15:53:15.133Z,1746460395.133 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-05-05T15:53:15.133Z,1746460395.133 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-05-05T15:53:15.350Z,1746460395.350 [CTD_Seabird] Loaded
2025-05-05T15:53:15.350Z,1746460395.350 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-05-05T15:53:15.351Z,1746460395.351 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2025-05-05T15:53:15.352Z,1746460395.352 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1091
2025-05-05T15:53:15.375Z,1746460395.375 [PAR_Licor] Loaded
2025-05-05T15:53:15.375Z,1746460395.375 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-05-05T15:53:15.420Z,1746460395.420 [WetLabsBB2FL] Loaded
2025-05-05T15:53:15.420Z,1746460395.420 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-05-05T15:53:15.421Z,1746460395.421 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A774E0
2025-05-05T15:53:15.421Z,1746460395.421 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1092
2025-05-05T15:53:15.422Z,1746460395.422 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-05-05T15:53:15.423Z,1746460395.423 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-05-05T15:53:15.590Z,1746460395.590 [BuoyancyServo] Loaded
2025-05-05T15:53:15.590Z,1746460395.590 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-05-05T15:53:15.614Z,1746460395.614 [ElevatorServo] Loaded
2025-05-05T15:53:15.615Z,1746460395.615 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-05-05T15:53:15.638Z,1746460395.638 [MassServo] Loaded
2025-05-05T15:53:15.638Z,1746460395.638 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-05-05T15:53:15.660Z,1746460395.660 [RudderServo] Loaded
2025-05-05T15:53:15.661Z,1746460395.661 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-05-05T15:53:15.678Z,1746460395.678 [ThrusterHE] Loaded
2025-05-05T15:53:15.679Z,1746460395.679 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-05-05T15:53:15.679Z,1746460395.679 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-05-05T15:53:15.680Z,1746460395.680 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-05-05T15:53:15.752Z,1746460395.752 [VerticalControl](DEBUG): Construct VerticalControl.
2025-05-05T15:53:15.804Z,1746460395.804 [VerticalControl] Loaded
2025-05-05T15:53:15.804Z,1746460395.804 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-05-05T15:53:15.807Z,1746460395.807 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-05-05T15:53:15.850Z,1746460395.850 [HorizontalControl] Loaded
2025-05-05T15:53:15.851Z,1746460395.851 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-05-05T15:53:15.853Z,1746460395.853 [SpeedControl](DEBUG): Construct SpeedControl.
2025-05-05T15:53:15.855Z,1746460395.855 [SpeedControl] Loaded
2025-05-05T15:53:15.855Z,1746460395.855 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-05-05T15:53:15.858Z,1746460395.858 [LoopControl](DEBUG): Construct LoopControl.
2025-05-05T15:53:15.859Z,1746460395.859 [LoopControl] Loaded
2025-05-05T15:53:15.859Z,1746460395.859 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-05-05T15:53:15.859Z,1746460395.859 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-05-05T15:53:15.860Z,1746460395.860 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-05-05T15:53:16.024Z,1746460396.024 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-05-05T15:53:16.025Z,1746460396.025 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-05-05T15:53:16.239Z,1746460396.239 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-05-05T15:53:16.240Z,1746460396.240 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-05-05T15:53:16.650Z,1746460396.650 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-05-05T15:53:16.650Z,1746460396.650 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-05-05T15:53:16.737Z,1746460396.737 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-05-05T15:53:16.744Z,1746460396.744 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-05-05T15:53:16.746Z,1746460396.746 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-05-05T15:53:16.758Z,1746460396.758 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-05-05T15:53:16.759Z,1746460396.759 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0
2025-05-05T15:53:16.759Z,1746460396.759 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1093
2025-05-05T15:53:16.764Z,1746460396.764 [Supervisor](INFO): Main Thread ID is 998
2025-05-05T15:53:16.764Z,1746460396.764 [Supervisor](DEBUG): Running supervisor.
2025-05-05T15:53:16.764Z,1746460396.764 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1094
2025-05-05T15:53:16.765Z,1746460396.765 [CommandExec](INFO): Initializing the command executive.
2025-05-05T15:53:16.767Z,1746460396.767 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1095
2025-05-05T15:53:16.769Z,1746460396.769 [controlThread ThreadHandler](INFO): Handler Thread ID is 1096
2025-05-05T15:53:16.769Z,1746460396.769 [controlThread](DEBUG): Initializing ControlThread
2025-05-05T15:53:16.770Z,1746460396.770 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-05-05T15:53:16.770Z,1746460396.770 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-05-05T15:53:16.771Z,1746460396.771 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-05-05T15:53:16.771Z,1746460396.771 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-05-05T15:53:16.772Z,1746460396.772 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-05-05T15:53:16.776Z,1746460396.776 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-05-05T15:53:16.776Z,1746460396.776 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-05-05T15:53:16.777Z,1746460396.777 [SBIT](INFO): Initialize SBIT Component.
2025-05-05T15:53:16.777Z,1746460396.777 [SBIT](IMPORTANT): git: 2025-04-24
2025-05-05T15:53:16.777Z,1746460396.777 [SBIT](INFO): git hash: ed8b2699e10264a13705e958152987274a27a0ee
2025-05-05T15:53:16.778Z,1746460396.778 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-05-05T15:53:16.779Z,1746460396.779 [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-05-05T15:53:16.780Z,1746460396.780 [SBIT](INFO): Beginning SBIT in 121.000000 seconds.
2025-05-05T15:53:16.780Z,1746460396.780 [IBIT](INFO): Initialize IBIT Component.
2025-05-05T15:53:16.781Z,1746460396.781 [CBIT](DEBUG): Initialize CBIT Component.
2025-05-05T15:53:16.782Z,1746460396.782 [logger ThreadHandler](INFO): Handler Thread ID is 1097
2025-05-05T15:53:16.795Z,1746460396.795 [CBIT](DEBUG): Initialized mux pins.
2025-05-05T15:53:16.795Z,1746460396.795 [CBIT](DEBUG): Initializing the watchdog timer.
2025-05-05T15:53:16.808Z,1746460396.808 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1098
2025-05-05T15:53:16.819Z,1746460396.819 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-05-05T15:53:16.820Z,1746460396.820 [CBIT](DEBUG): Initializing heartbeat.
2025-05-05T15:53:16.820Z,1746460396.820 [DAT ThreadHandler](INFO): Handler Thread ID is 1099
2025-05-05T15:53:16.821Z,1746460396.821 [DAT](INFO): Powering up
2025-05-05T15:53:16.821Z,1746460396.821 [DAT](DEBUG): Initializing DAT.
2025-05-05T15:53:16.825Z,1746460396.825 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1101
2025-05-05T15:53:16.826Z,1746460396.826 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-05-05T15:53:16.848Z,1746460396.848 [Onboard ThreadHandler](INFO): Handler Thread ID is 1102
2025-05-05T15:53:16.865Z,1746460396.865 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1103
2025-05-05T15:53:16.877Z,1746460396.877 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1104
2025-05-05T15:53:16.878Z,1746460396.878 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-05-05T15:53:16.884Z,1746460396.884 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1106
2025-05-05T15:53:16.887Z,1746460396.887 [WetLabsBB2FL](INFO): Powering up
2025-05-05T15:53:16.889Z,1746460396.889 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1108
2025-05-05T15:53:16.891Z,1746460396.891 [CBIT](DEBUG): Deactivating emergency mode.
2025-05-05T15:53:16.894Z,1746460396.894 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-05-05T15:53:16.895Z,1746460396.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-05-05T15:53:16.895Z,1746460396.895 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-05-05T15:53:16.895Z,1746460396.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-05-05T15:53:16.896Z,1746460396.896 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-05-05T15:53:16.896Z,1746460396.896 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-05-05T15:53:16.896Z,1746460396.896 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-05-05T15:53:16.896Z,1746460396.896 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-05-05T15:53:16.931Z,1746460396.931 [CBIT](DEBUG): Backplane powered.
2025-05-05T15:53:16.931Z,1746460396.931 [GFScanner](DEBUG): Initializing GFScanner
2025-05-05T15:53:16.932Z,1746460396.932 [GFScanner](DEBUG): Deactivating GF circuits.
2025-05-05T15:53:16.941Z,1746460396.941 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-05-05T15:53:16.942Z,1746460396.942 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-05-05T15:53:16.943Z,1746460396.943 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-05-05T15:53:16.944Z,1746460396.944 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-05-05T15:53:16.944Z,1746460396.944 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-05-05T15:53:16.945Z,1746460396.945 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-05-05T15:53:16.945Z,1746460396.945 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-05-05T15:53:16.950Z,1746460396.950 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-05-05T15:53:16.992Z,1746460396.992 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-05-05T15:53:17.028Z,1746460397.028 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-05T15:53:17.052Z,1746460397.052 [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-05-05T15:53:17.053Z,1746460397.053 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-05-05T15:53:17.053Z,1746460397.053 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-05-05T15:53:17.056Z,1746460397.056 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-05-05T15:53:17.279Z,1746460397.279 [Radio_Surface](INFO): Powering up
2025-05-05T15:53:17.281Z,1746460397.281 [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-05-05T15:53:17.299Z,1746460397.299 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-05-05T15:53:17.301Z,1746460397.301 [Default:A.Wait](DEBUG): Construct Wait.
2025-05-05T15:53:17.303Z,1746460397.303 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-05T15:53:17.327Z,1746460397.327 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-05-05T15:53:17.333Z,1746460397.333 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-05-05T15:53:17.342Z,1746460397.342 [Default:E.Execute](DEBUG): Construct Execute.
2025-05-05T15:53:17.345Z,1746460397.345 [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-05-05T15:53:17.359Z,1746460397.359 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-05-05T15:53:17.367Z,1746460397.367 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-05-05T15:53:17.428Z,1746460397.428 [Depth_Keller](INFO): Initializing.
2025-05-05T15:53:17.429Z,1746460397.429 [MultiRay](INFO): Powering up MultiRay Lights
2025-05-05T15:53:17.429Z,1746460397.429 [MultiRay](INFO): Powering up secondary power supply.
2025-05-05T15:53:17.461Z,1746460397.461 [Power24vConverter](INFO): Powering up.
2025-05-05T15:53:17.479Z,1746460397.479 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-05-05T15:53:17.578Z,1746460397.578 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-05-05T15:53:17.591Z,1746460397.591 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-05-05T15:53:17.592Z,1746460397.592 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-05-05T15:53:17.599Z,1746460397.599 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-05-05T15:53:17.600Z,1746460397.600 [MassServo](DEBUG): Initializing EZServoServo.
2025-05-05T15:53:17.615Z,1746460397.615 [MassServo](DEBUG): Initializing MassServo.
2025-05-05T15:53:17.616Z,1746460397.616 [RudderServo](DEBUG): Initializing EZServoServo.
2025-05-05T15:53:17.624Z,1746460397.624 [RudderServo](DEBUG): Initializing RudderServo.
2025-05-05T15:53:17.625Z,1746460397.625 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-05-05T15:53:17.631Z,1746460397.631 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-05-05T15:53:17.809Z,1746460397.809 [Depth_Keller](ERROR): Pressure or depth reading out of range: 816.065491 decibar, 0.000000 m
2025-05-05T15:53:17.869Z,1746460397.869 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-05-05T15:53:18.579Z,1746460398.579 [MultiRay](INFO): Powering down
2025-05-05T15:53:18.699Z,1746460398.699 [MultiRay](INFO): Powering down LCB2
2025-05-05T15:53:19.499Z,1746460399.499 [WetLabsBB2FL](INFO): Powering down
2025-05-05T15:53:27.521Z,1746460407.521 [DataOverHttps](IMPORTANT): SBD MTMSN=20250505T155326
2025-05-05T15:53:27.526Z,1746460407.526 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005291
2025-05-05T15:53:28.664Z,1746460408.664 [DAT](INFO): DAT read:
2025-05-05T15:53:28.665Z,1746460408.665 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-05-05T15:53:30.176Z,1746460410.176 [DAT](INFO): DAT read: MF Frequency Band
2025-05-05T15:53:30.177Z,1746460410.177 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-05-05T15:53:30.178Z,1746460410.178 [DAT](INFO): DAT read: May 1 2025 23:14:42
2025-05-05T15:53:31.436Z,1746460411.436 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-05-05T15:53:31.438Z,1746460411.438 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-05-05T15:53:31.438Z,1746460411.438 [DAT](INFO): commRate: 800
2025-05-05T15:53:33.504Z,1746460413.504 [DAT](INFO): entering command mode
2025-05-05T15:53:33.704Z,1746460413.704 [DAT](INFO): DAT read:
2025-05-05T15:53:33.704Z,1746460413.704 [DAT](INFO): DAT read: user:1>
2025-05-05T15:53:33.705Z,1746460413.705 [DAT](INFO): setting verbose to 3
2025-05-05T15:53:33.956Z,1746460413.956 [DAT](INFO): DAT read: user:1>
2025-05-05T15:53:33.957Z,1746460413.957 [DAT](INFO): DAT read: Verbose | 3
2025-05-05T15:53:33.957Z,1746460413.957 [DAT](INFO): set verbose to 3
2025-05-05T15:53:33.958Z,1746460413.958 [DAT](INFO): setting DatVerbose to 27440
2025-05-05T15:53:34.208Z,1746460414.208 [DAT](INFO): DAT read: user:2>
2025-05-05T15:53:34.209Z,1746460414.209 [DAT](INFO): DAT read: DatVerbose | 27440
2025-05-05T15:53:34.209Z,1746460414.209 [DAT](INFO): set DatVerbose to 27440
2025-05-05T15:53:34.209Z,1746460414.209 [DAT](INFO): setting transmit power to 8
2025-05-05T15:53:34.462Z,1746460414.462 [DAT](INFO): DAT read: user:3>
2025-05-05T15:53:34.463Z,1746460414.463 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-05-05T15:53:34.463Z,1746460414.463 [DAT](INFO): set transmit power to 8
2025-05-05T15:53:34.463Z,1746460414.463 [DAT](INFO): setting local address to 9
2025-05-05T15:53:34.712Z,1746460414.712 [DAT](INFO): DAT read: user:4>
2025-05-05T15:53:34.713Z,1746460414.713 [DAT](INFO): DAT read: LocalAddr | 9
2025-05-05T15:53:34.713Z,1746460414.713 [DAT](INFO): set local address to 9
2025-05-05T15:53:34.714Z,1746460414.714 [DAT](INFO): Setting time to: 15:53:34 And date to:5/5/2025
2025-05-05T15:53:34.910Z,1746460414.910 [DataOverHttps](INFO): Received command: failComponent
2025-05-05T15:53:34.964Z,1746460414.964 [DAT](INFO): DAT read: user:5>
2025-05-05T15:53:34.965Z,1746460414.965 [DAT](INFO): DAT read: Mon May 5, 2025 15:53:34
2025-05-05T15:53:34.965Z,1746460414.965 [DAT](INFO): Local DAT time set to Mon May 5, 2025 15:53:34
2025-05-05T15:53:34.985Z,1746460414.985 [CommandExec](IMPORTANT): got command failComponent
2025-05-05T15:53:34.985Z,1746460414.985 [CommandExec](IMPORTANT): Failed components:
2025-05-05T15:53:34.985Z,1746460414.985 [CommandExec](IMPORTANT): No failed Components.
2025-05-05T15:53:44.946Z,1746460424.946 [NAL9602](INFO): Powering up NAL9602
2025-05-05T15:53:55.853Z,1746460435.853 [NAL9602](INFO): NAL9602 initialized
2025-05-05T15:54:20.289Z,1746460460.289 [CommandExec](IMPORTANT): got command strobe off
2025-05-05T15:54:20.289Z,1746460460.289 [CommandExec](IMPORTANT): Deactivating strobe
2025-05-05T15:54:24.868Z,1746460464.868 [CommandExec](IMPORTANT): got command failComponent
2025-05-05T15:54:24.868Z,1746460464.868 [CommandExec](IMPORTANT): Failed components:
2025-05-05T15:54:24.868Z,1746460464.868 [CommandExec](IMPORTANT): No failed Components.
2025-05-05T15:54:33.358Z,1746460473.358 [CommandExec](IMPORTANT): got command get Onboard.Pressure pound_per_square_inch
2025-05-05T15:54:33.359Z,1746460473.359 [CommandExec](IMPORTANT): Onboard.Pressure 9.895759 psi
2025-05-05T15:54:38.809Z,1746460478.809 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2025-05-05T15:54:38.809Z,1746460478.809 [CommandExec](IMPORTANT): Onboard.Humidity 10.792333 %
2025-05-05T15:55:18.570Z,1746460518.570 [SBIT](IMPORTANT): Beginning Startup BIT
2025-05-05T15:55:18.578Z,1746460518.578 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-05T15:55:22.928Z,1746460522.928 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.003751
CHAN A1 (24V): 0.002152
CHAN A2 (12V): -0.005723
CHAN A3 (5V): -0.003146
CHAN B0 (3.3V): -0.001307
CHAN B1 (3.15aV): -0.001317
CHAN B2 (3.15bV): -0.001965
CHAN B3 (GND): -0.001434
OPEN: 0.005064
Full Scale: +/- 1 mA
2025-05-05T15:56:12.576Z,1746460572.576 [SBIT](IMPORTANT): SBIT PASSED
2025-05-05T15:56:12.576Z,1746460572.576 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-05-05T15:56:12.577Z,1746460572.577 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;
2025-05-05T15:56:12.577Z,1746460572.577 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-05-05T15:56:12.577Z,1746460572.577 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;
2025-05-05T15:56:12.577Z,1746460572.577 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): MultiRay.brightnessWhite=88 none;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): MultiRay.loadAtStartup=1 bool;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): NAL9602.fastGPSFix=0 bool;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=204.697 cubic_centimeter;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): VerticalControl.massDefault=25.462118 millimeter;
2025-05-05T15:56:12.578Z,1746460572.578 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool;
2025-05-05T15:56:12.929Z,1746460572.929 [MissionManager](IMPORTANT): Started mission Startup
2025-05-05T15:56:12.930Z,1746460572.930 [Startup] Running Loop=1
2025-05-05T15:56:12.930Z,1746460572.930 [Startup](DEBUG): Aggregate::initialize Startup
2025-05-05T15:56:12.930Z,1746460572.930 [Startup:A.GoToSurface] Running Loop=1
2025-05-05T15:56:12.930Z,1746460572.930 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-05T15:56:12.931Z,1746460572.931 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-05T15:56:12.935Z,1746460572.935 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-05T15:56:12.935Z,1746460572.935 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-05T15:56:12.936Z,1746460572.936 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-05T15:56:12.936Z,1746460572.936 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-05T15:56:12.936Z,1746460572.936 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-05T15:56:12.938Z,1746460572.938 [Startup:StartupSatComms] Running Loop=1
2025-05-05T15:56:12.938Z,1746460572.938 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-05-05T15:56:12.938Z,1746460572.938 [Startup:StartupSatComms:A] Running Loop=1
2025-05-05T15:56:13.326Z,1746460573.326 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-05-05T15:56:16.940Z,1746460576.940 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-05-05T15:56:16.940Z,1746460576.940 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T15:56:16.950Z,1746460576.950 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T15:56:17.361Z,1746460577.361 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T15:56:17.361Z,1746460577.361 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-05-05T15:57:13.110Z,1746460633.110 [Startup:StartupSatComms:A](INFO): Timed out from 2025-05-05T15:56:12.9Z
2025-05-05T15:57:13.110Z,1746460633.110 [Startup:StartupSatComms:A] Stopped
2025-05-05T15:57:13.110Z,1746460633.110 [Startup:StartupSatComms:B] Running Loop=1
2025-05-05T15:57:13.517Z,1746460633.517 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-05T15:57:20.523Z,1746460640.523 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250505T155304/Courier0000.lzma
2025-05-05T15:57:21.525Z,1746460641.525 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0000.lzma.bak
2025-05-05T15:57:21.525Z,1746460641.525 [DataOverHttps](INFO): SBD MOMSN=24773078
2025-05-05T15:57:37.626Z,1746460657.626 [DataOverHttps](INFO): Sending 1109 bytes from file Logs/20250505T155304/Express0001.lzma
2025-05-05T15:57:38.625Z,1746460658.625 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0001.lzma.bak
2025-05-05T15:57:38.625Z,1746460658.625 [DataOverHttps](INFO): SBD MOMSN=24773081
2025-05-05T15:57:54.287Z,1746460674.287 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250505T155304/Express0005.lzma
2025-05-05T15:57:55.289Z,1746460675.289 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0005.lzma.bak
2025-05-05T15:57:55.289Z,1746460675.289 [DataOverHttps](INFO): SBD MOMSN=24773118
2025-05-05T15:57:56.320Z,1746460676.320 [Startup:StartupSatComms:B] Stopped
2025-05-05T15:57:56.321Z,1746460676.321 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-05-05T15:57:56.321Z,1746460676.321 [Startup:StartupSatComms] Stopped
2025-05-05T15:57:56.321Z,1746460676.321 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-05-05T15:57:56.322Z,1746460676.322 [Startup](INFO): Completed Startup
2025-05-05T15:57:56.322Z,1746460676.322 [MissionManager](INFO): Startup is completed.
2025-05-05T15:57:56.322Z,1746460676.322 [MissionManager](INFO): Uninitializing Mission Startup
2025-05-05T15:57:56.322Z,1746460676.322 [Startup] Stopped
2025-05-05T15:57:56.322Z,1746460676.322 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-05-05T15:57:56.322Z,1746460676.322 [Startup:A.GoToSurface] Stopped
2025-05-05T15:57:56.322Z,1746460676.322 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-05-05T15:57:56.729Z,1746460676.729 [MissionManager](IMPORTANT): Started mission Default
2025-05-05T15:57:56.729Z,1746460676.729 [Default] Running Loop=1
2025-05-05T15:57:56.730Z,1746460676.730 [Default](DEBUG): Aggregate::initialize Default
2025-05-05T15:57:56.730Z,1746460676.730 [Default:B.GoToSurface] Running Loop=1
2025-05-05T15:57:56.730Z,1746460676.730 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-05T15:57:56.730Z,1746460676.730 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-05T15:57:56.730Z,1746460676.730 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-05T15:57:56.730Z,1746460676.730 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-05T15:57:56.731Z,1746460676.731 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-05T15:57:56.731Z,1746460676.731 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-05T15:57:56.732Z,1746460676.732 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-05T15:57:56.732Z,1746460676.732 [Default:A.Wait] Running Loop=1
2025-05-05T15:57:56.732Z,1746460676.732 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-05-05T15:58:10.075Z,1746460690.075 [Default:A.Wait](INFO): Done Waiting.
2025-05-05T15:58:10.075Z,1746460690.075 [Default:A.Wait] Stopped
2025-05-05T15:58:10.075Z,1746460690.075 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T15:58:10.481Z,1746460690.481 [Default:CheckIn] Running Loop=1
2025-05-05T15:58:10.482Z,1746460690.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T15:58:10.482Z,1746460690.482 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T15:58:10.878Z,1746460690.878 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-05-05T15:58:58.937Z,1746460738.937 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-05T15:59:17.948Z,1746460757.948 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-05-05T15:59:17.948Z,1746460757.948 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T15:59:17.987Z,1746460757.987 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T15:59:18.360Z,1746460758.360 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T15:59:18.360Z,1746460758.360 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-05-05T15:59:31.772Z,1746460771.772 [CommandExec](IMPORTANT): got command burn on
2025-05-05T15:59:31.772Z,1746460771.772 [CommandExec](IMPORTANT): Activating dropweight wire
2025-05-05T15:59:35.624Z,1746460775.624 [CommandExec](IMPORTANT): got command burn off
2025-05-05T15:59:35.624Z,1746460775.624 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-05-05T16:00:42.369Z,1746460842.369 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-05-05T16:00:42.378Z,1746460842.378 [BPC1](INFO): Received data from all battery sticks.
2025-05-05T16:02:18.952Z,1746460938.952 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-05-05T16:02:18.952Z,1746460938.952 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:02:18.962Z,1746460938.962 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:02:19.366Z,1746460939.366 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:02:19.367Z,1746460939.367 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-05-05T16:03:09.512Z,1746460989.512 [CommandExec](IMPORTANT): got command gfscan
2025-05-05T16:03:09.859Z,1746460989.859 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-05T16:03:10.661Z,1746460990.661 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-05T15:58:10.5Z
2025-05-05T16:03:10.661Z,1746460990.661 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T16:03:10.662Z,1746460990.662 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T16:03:11.038Z,1746460991.038 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-05T16:03:14.328Z,1746460994.328 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.001517
CHAN A1 (24V): 0.002028
CHAN A2 (12V): -0.005052
CHAN A3 (5V): -0.003691
CHAN B0 (3.3V): -0.001504
CHAN B1 (3.15aV): -0.001347
CHAN B2 (3.15bV): -0.001455
CHAN B3 (GND): -0.000492
OPEN: 0.004790
Full Scale: +/- 1 mA
2025-05-05T16:03:18.363Z,1746460998.363 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250505T155304/Courier0007.lzma
2025-05-05T16:03:19.365Z,1746460999.365 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0007.lzma.bak
2025-05-05T16:03:19.365Z,1746460999.365 [DataOverHttps](INFO): SBD MOMSN=24773132
2025-05-05T16:03:21.168Z,1746461001.168 [CommandExec](IMPORTANT): got command failComponent
2025-05-05T16:03:21.168Z,1746461001.168 [CommandExec](IMPORTANT): Failed components:
2025-05-05T16:03:21.168Z,1746461001.168 [CommandExec](IMPORTANT): No failed Components.
2025-05-05T16:03:35.276Z,1746461015.276 [DataOverHttps](INFO): Sending 288 bytes from file Logs/20250505T155304/Express0008.lzma
2025-05-05T16:03:36.277Z,1746461016.277 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0008.lzma.bak
2025-05-05T16:03:36.277Z,1746461016.277 [DataOverHttps](INFO): SBD MOMSN=24773134
2025-05-05T16:03:37.310Z,1746461017.310 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T16:03:37.310Z,1746461017.310 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T16:03:37.310Z,1746461017.310 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:03:57.088Z,1746461037.088 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-05T16:03:57.089Z,1746461037.089 [NAL9602] Data Fault, FailCount= 1
2025-05-05T16:03:57.089Z,1746461037.089 [NAL9602](ERROR): Data Fault
2025-05-05T16:03:57.106Z,1746461037.106 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-05T16:03:57.485Z,1746461037.485 [NAL9602](INFO): Powering down
2025-05-05T16:03:58.319Z,1746461038.319 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-05T16:03:58.319Z,1746461038.319 [NAL9602] No Fault, FailCount= 1
2025-05-05T16:04:27.797Z,1746461067.797 [NAL9602](INFO): Powering up NAL9602
2025-05-05T16:04:38.697Z,1746461078.697 [NAL9602](INFO): NAL9602 initialized
2025-05-05T16:05:19.912Z,1746461119.912 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-05-05T16:05:19.912Z,1746461119.912 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:05:19.922Z,1746461119.922 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:05:20.328Z,1746461120.328 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:05:20.328Z,1746461120.328 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-05-05T16:07:52.793Z,1746461272.793 [DataOverHttps](IMPORTANT): SBD MTMSN=20250505T160751
2025-05-05T16:08:00.235Z,1746461280.235 [DataOverHttps](INFO): Received command: run Engineering/lab_test_optim.tl
2025-05-05T16:08:00.373Z,1746461280.373 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-05-05T16:08:00.374Z,1746461280.374 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-05-05T16:08:00.374Z,1746461280.374 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-05-05T16:08:00.378Z,1746461280.378 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-05-05T16:08:00.626Z,1746461280.626 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-05-05T16:08:00.640Z,1746461280.640 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-05-05T16:08:00.644Z,1746461280.644 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-05-05T16:08:00.646Z,1746461280.646 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-05-05T16:08:00.650Z,1746461280.650 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-05-05T16:08:00.653Z,1746461280.653 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-05-05T16:08:00.656Z,1746461280.656 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-05-05T16:08:00.659Z,1746461280.659 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-05-05T16:08:00.662Z,1746461280.662 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-05-05T16:08:00.662Z,1746461280.662 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-05-05T16:08:00.662Z,1746461280.662 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-05-05T16:08:00.663Z,1746461280.663 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-05-05T16:08:00.718Z,1746461280.718 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-05-05T16:08:00.739Z,1746461280.739 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-05-05T16:08:00.750Z,1746461280.750 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-05-05T16:08:00.790Z,1746461280.790 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-05-05T16:08:00.832Z,1746461280.832 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-05-05T16:08:00.834Z,1746461280.834 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-05-05T16:08:00.850Z,1746461280.850 [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 lab_test_optim {
arguments {
MissionTimeout = 15 minute
"""
Backseat will stay on for this duration, independent of Optim state
"""
RecordTime = 1 minute
"""
How long to record after startup sequence (hopefully) turns on Optim camera
"""
BackseatWait = 30 second
"""
How long to wait for the backseat to power up before attempting to power the Optim
"""
LightMode = 2 count
"""
Mode for Multiray lights. 0 is off, 1 is red, 2 is white
"""
BrightnessWhite = 100 none_int
"""
White Multiray LED brightness, 0-100
"""
BrightnessRed = 100 none_int
"""
Red Multiray LED brightness, 0-100
"""
}
output {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
readData strategy="MinError" {
while ( LightsEnabled )
Sensor:MultiRay.lightModeLog
}
aggregate Startup {
run in sequence
syslog important "Waiting " + BackseatWait~s + " for backseat to start up..."
behavior Guidance:Wait {
run in sequence
set duration = BackseatWait
}
}
aggregate Run {
run in sequence
syslog important "Trying to run Optim and Multiray forreal"
assign in sequence RecordingEnabled = true
assign in sequence LightsEnabled = true
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode
aggregate setRed {
run in sequence
break if ( LightMode != 1 count )
assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
syslog info "Setting multiray red brightness to" + BrightnessRed~count
}
aggregate setWhite {
run in sequence
break if ( LightMode != 2 count )
assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
syslog info "Setting muliray white brightness to" + BrightnessWhite~count
}
syslog important "Recording for " + RecordTime~min
behavior Guidance:Wait {
run in sequence
set duration = RecordTime
}
}
behavior Guidance:Wait {
run in sequence
set duration = MissionTimeout
}
}
2025-05-05T16:08:00.861Z,1746461280.861 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-05-05T16:08:01.135Z,1746461281.135 [Default] Stopped
2025-05-05T16:08:01.135Z,1746461281.135 [Default](DEBUG): Aggregate::uninitialize Default
2025-05-05T16:08:01.135Z,1746461281.135 [Default:B.GoToSurface] Stopped
2025-05-05T16:08:01.135Z,1746461281.135 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-05-05T16:08:01.135Z,1746461281.135 [Default:CheckIn] Stopped
2025-05-05T16:08:01.136Z,1746461281.136 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T16:08:01.136Z,1746461281.136 [Default:CheckIn:C.Wait] Stopped
2025-05-05T16:08:01.136Z,1746461281.136 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:08:01.136Z,1746461281.136 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-05-05T16:08:01.136Z,1746461281.136 [lab_test_optim] Running Loop=1
2025-05-05T16:08:01.136Z,1746461281.136 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-05-05T16:08:01.136Z,1746461281.136 [lab_test_optim:BackseatDriver] Running Loop=1
2025-05-05T16:08:01.136Z,1746461281.136 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-05-05T16:08:01.137Z,1746461281.137 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-05-05T16:08:01.137Z,1746461281.137 [lab_test_optim:B] Running Loop=1
2025-05-05T16:08:01.137Z,1746461281.137 [lab_test_optim:C] Running Loop=1
2025-05-05T16:08:01.137Z,1746461281.137 [lab_test_optim:D] Running Loop=1
2025-05-05T16:08:01.137Z,1746461281.137 [lab_test_optim:Startup] Running Loop=1
2025-05-05T16:08:01.137Z,1746461281.137 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-05-05T16:08:01.137Z,1746461281.137 [lab_test_optim:Startup:A] Running Loop=1
2025-05-05T16:08:01.138Z,1746461281.138 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-05-05T16:08:01.138Z,1746461281.138 [lab_test_optim:Startup:A] Stopped
2025-05-05T16:08:01.138Z,1746461281.138 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-05-05T16:08:01.138Z,1746461281.138 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:08:01.138Z,1746461281.138 [lab_test_optim:D] Stopped
2025-05-05T16:08:01.138Z,1746461281.138 [lab_test_optim:C] Stopped
2025-05-05T16:08:01.138Z,1746461281.138 [lab_test_optim:B] Running Loop=1
2025-05-05T16:08:01.139Z,1746461281.139 [lab_test_optim:BackseatDriver] Running Loop=1
2025-05-05T16:08:01.139Z,1746461281.139 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-05-05T16:08:01.239Z,1746461281.239 [BackseatComponent](INFO): Powering up
2025-05-05T16:08:01.240Z,1746461281.240 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-05-05T16:08:20.905Z,1746461300.905 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-05-05T16:08:20.905Z,1746461300.905 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:08:20.915Z,1746461300.915 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:08:21.323Z,1746461301.323 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:08:21.323Z,1746461301.323 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-05-05T16:08:31.849Z,1746461311.849 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-05-05T16:08:31.849Z,1746461311.849 [lab_test_optim:Startup:B.Wait] Stopped
2025-05-05T16:08:31.849Z,1746461311.849 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:08:31.849Z,1746461311.849 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-05-05T16:08:31.849Z,1746461311.849 [lab_test_optim:Startup] Stopped
2025-05-05T16:08:31.849Z,1746461311.849 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-05-05T16:08:31.850Z,1746461311.850 [lab_test_optim:Run] Running Loop=1
2025-05-05T16:08:31.850Z,1746461311.850 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-05-05T16:08:31.850Z,1746461311.850 [lab_test_optim:Run:A] Running Loop=1
2025-05-05T16:08:32.232Z,1746461312.232 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-05-05T16:08:32.232Z,1746461312.232 [lab_test_optim:Run:A] Stopped
2025-05-05T16:08:32.232Z,1746461312.232 [lab_test_optim:Run:B] Running Loop=1
2025-05-05T16:08:32.671Z,1746461312.671 [lab_test_optim:Run:B] Stopped
2025-05-05T16:08:32.671Z,1746461312.671 [lab_test_optim:Run:C] Running Loop=1
2025-05-05T16:08:33.043Z,1746461313.043 [lab_test_optim:Run:C] Stopped
2025-05-05T16:08:33.047Z,1746461313.047 [lab_test_optim:Run:D] Running Loop=1
2025-05-05T16:08:33.047Z,1746461313.047 [lab_test_optim:C] Running Loop=1
2025-05-05T16:08:33.047Z,1746461313.047 [lab_test_optim:C] Running Loop=1
2025-05-05T16:08:33.048Z,1746461313.048 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-05-05T16:08:33.422Z,1746461313.422 [PowerOnly](INFO): Powering up loadControl
2025-05-05T16:08:33.469Z,1746461313.469 [lab_test_optim:Run:D] Stopped
2025-05-05T16:08:33.469Z,1746461313.469 [lab_test_optim:Run:setRed] Running Loop=1
2025-05-05T16:08:33.469Z,1746461313.469 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-05-05T16:08:33.469Z,1746461313.469 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-05-05T16:08:33.469Z,1746461313.469 [lab_test_optim:D] Running Loop=1
2025-05-05T16:08:33.470Z,1746461313.470 [lab_test_optim:D] Running Loop=1
2025-05-05T16:08:33.470Z,1746461313.470 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-05-05T16:08:33.873Z,1746461313.873 [lab_test_optim:Run:setRed] Stopped
2025-05-05T16:08:33.873Z,1746461313.873 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-05-05T16:08:33.873Z,1746461313.873 [lab_test_optim:Run:setRed:A] Stopped
2025-05-05T16:08:33.873Z,1746461313.873 [lab_test_optim:Run:setWhite] Running Loop=1
2025-05-05T16:08:33.873Z,1746461313.873 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-05-05T16:08:33.873Z,1746461313.873 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-05-05T16:08:34.297Z,1746461314.297 [lab_test_optim:Run:setWhite:A] Stopped
2025-05-05T16:08:34.298Z,1746461314.298 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-05-05T16:08:34.702Z,1746461314.702 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-05-05T16:08:34.702Z,1746461314.702 [lab_test_optim:Run:setWhite:B] Stopped
2025-05-05T16:08:34.702Z,1746461314.702 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-05-05T16:08:34.702Z,1746461314.702 [lab_test_optim:Run:setWhite] Stopped
2025-05-05T16:08:34.702Z,1746461314.702 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-05-05T16:08:34.702Z,1746461314.702 [lab_test_optim:Run:G] Running Loop=1
2025-05-05T16:08:35.068Z,1746461315.068 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-05-05T16:08:35.068Z,1746461315.068 [lab_test_optim:Run:G] Stopped
2025-05-05T16:08:35.068Z,1746461315.068 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-05-05T16:08:35.068Z,1746461315.068 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:08:35.845Z,1746461315.845 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-05-05T16:08:59.408Z,1746461339.408 [BackseatComponent](IMPORTANT): ikshana: running backseat application.
2025-05-05T16:09:02.113Z,1746461342.113 [BackseatComponent](INFO): Created universal data reader for depth with code: 6
2025-05-05T16:09:02.114Z,1746461342.114 [BackseatComponent](INFO): Requesting data from depth (6). Requested size is: 1
2025-05-05T16:09:35.666Z,1746461375.666 [lab_test_optim:Run:H.Wait](INFO): Done Waiting.
2025-05-05T16:09:35.666Z,1746461375.666 [lab_test_optim:Run:H.Wait] Stopped
2025-05-05T16:09:35.666Z,1746461375.666 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:09:35.666Z,1746461375.666 [lab_test_optim:Run](INFO): Completed lab_test_optim:Run
2025-05-05T16:09:35.666Z,1746461375.666 [lab_test_optim:Run] Stopped
2025-05-05T16:09:35.666Z,1746461375.666 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-05-05T16:09:35.666Z,1746461375.666 [lab_test_optim:G.Wait] Running Loop=1
2025-05-05T16:09:35.667Z,1746461375.667 [lab_test_optim:G.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:11:21.897Z,1746461481.897 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-05-05T16:11:21.897Z,1746461481.897 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:11:21.912Z,1746461481.912 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:11:22.312Z,1746461482.312 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:11:22.312Z,1746461482.312 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-05-05T16:11:34.252Z,1746461494.252 [DataOverHttps](IMPORTANT): SBD MTMSN=20250505T161133
2025-05-05T16:11:41.599Z,1746461501.599 [DataOverHttps](INFO): Received command: stop
2025-05-05T16:11:41.672Z,1746461501.672 [CommandExec](IMPORTANT): got command stop
2025-05-05T16:11:41.672Z,1746461501.672 [CommandExec](IMPORTANT): Scheduling is paused
2025-05-05T16:11:41.672Z,1746461501.672 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-05-05T16:11:41.719Z,1746461501.719 [MissionManager](INFO): MissionManager is completed.
2025-05-05T16:11:41.719Z,1746461501.719 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim] Stopped
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:BackseatDriver] Stopped
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:B] Stopped
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:C] Stopped
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:D] Stopped
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:G.Wait] Stopped
2025-05-05T16:11:41.720Z,1746461501.720 [lab_test_optim:G.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:11:41.823Z,1746461501.823 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-05-05T16:11:41.823Z,1746461501.823 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-05-05T16:11:42.121Z,1746461502.121 [MissionManager](IMPORTANT): Started mission Default
2025-05-05T16:11:42.121Z,1746461502.121 [Default] Running Loop=1
2025-05-05T16:11:42.121Z,1746461502.121 [Default](DEBUG): Aggregate::initialize Default
2025-05-05T16:11:42.121Z,1746461502.121 [Default:B.GoToSurface] Running Loop=1
2025-05-05T16:11:42.121Z,1746461502.121 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-05T16:11:42.122Z,1746461502.122 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-05T16:11:42.122Z,1746461502.122 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-05T16:11:42.122Z,1746461502.122 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-05T16:11:42.123Z,1746461502.123 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-05T16:11:42.123Z,1746461502.123 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-05T16:11:42.123Z,1746461502.123 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-05T16:11:42.124Z,1746461502.124 [Default:A.Wait] Running Loop=1
2025-05-05T16:11:42.124Z,1746461502.124 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:11:42.493Z,1746461502.493 [MultiRay](INFO): Powering down
2025-05-05T16:11:42.608Z,1746461502.608 [MultiRay](INFO): Powering down LCB2
2025-05-05T16:11:55.430Z,1746461515.430 [Default:A.Wait](INFO): Done Waiting.
2025-05-05T16:11:55.430Z,1746461515.430 [Default:A.Wait] Stopped
2025-05-05T16:11:55.430Z,1746461515.430 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:11:55.838Z,1746461515.838 [Default:CheckIn] Running Loop=1
2025-05-05T16:11:55.838Z,1746461515.838 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T16:11:55.838Z,1746461515.838 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T16:11:59.000Z,1746461520.000 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-05-05T16:12:00.000Z,1746461520.000 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-05-05T16:12:00.001Z,1746461520.001 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-05-05T16:13:12.178Z,1746461592.178 [PowerOnly](INFO): Powering down loadControl
2025-05-05T16:14:22.942Z,1746461662.942 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-05-05T16:14:22.942Z,1746461662.942 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:14:22.957Z,1746461662.957 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:14:23.338Z,1746461663.338 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:14:23.338Z,1746461663.338 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-05-05T16:14:41.869Z,1746461681.869 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-05T16:14:41.869Z,1746461681.869 [NAL9602] Data Fault, FailCount= 2
2025-05-05T16:14:41.869Z,1746461681.869 [NAL9602](ERROR): Data Fault
2025-05-05T16:14:41.915Z,1746461681.915 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-05T16:14:42.270Z,1746461682.270 [NAL9602](INFO): Powering down
2025-05-05T16:14:43.103Z,1746461683.103 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-05T16:14:43.103Z,1746461683.103 [NAL9602] No Fault, FailCount= 2
2025-05-05T16:15:12.569Z,1746461712.569 [NAL9602](INFO): Powering up NAL9602
2025-05-05T16:15:23.481Z,1746461723.481 [NAL9602](INFO): NAL9602 initialized
2025-05-05T16:16:56.019Z,1746461816.019 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-05T16:11:55.8Z
2025-05-05T16:16:56.019Z,1746461816.019 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T16:16:56.020Z,1746461816.020 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T16:17:01.655Z,1746461821.655 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250505T155304/Courier0010.lzma
2025-05-05T16:17:02.657Z,1746461822.657 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0010.lzma.bak
2025-05-05T16:17:02.657Z,1746461822.657 [DataOverHttps](INFO): SBD MOMSN=24773173
2025-05-05T16:17:18.329Z,1746461838.329 [DataOverHttps](INFO): Sending 692 bytes from file Logs/20250505T155304/Express0011.lzma
2025-05-05T16:17:19.329Z,1746461839.329 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0011.lzma.bak
2025-05-05T16:17:19.329Z,1746461839.329 [DataOverHttps](INFO): SBD MOMSN=24773175
2025-05-05T16:17:23.919Z,1746461843.919 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-05-05T16:17:23.919Z,1746461843.919 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:17:23.952Z,1746461843.952 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:17:24.330Z,1746461844.330 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:17:24.330Z,1746461844.330 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-05-05T16:17:35.203Z,1746461855.203 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250505T155304/Express0014.lzma
2025-05-05T16:17:36.205Z,1746461856.205 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0014.lzma.bak
2025-05-05T16:17:36.205Z,1746461856.205 [DataOverHttps](INFO): SBD MOMSN=24773196
2025-05-05T16:17:37.234Z,1746461857.234 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T16:17:37.234Z,1746461857.234 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T16:17:37.234Z,1746461857.234 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:20:24.892Z,1746462024.892 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-05-05T16:20:24.892Z,1746462024.892 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:20:24.903Z,1746462024.903 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:20:25.310Z,1746462025.310 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:20:25.310Z,1746462025.310 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-05-05T16:22:37.809Z,1746462157.809 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T16:22:37.809Z,1746462157.809 [Default:CheckIn:C.Wait] Stopped
2025-05-05T16:22:37.809Z,1746462157.809 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:22:37.809Z,1746462157.809 [Default:CheckIn:D] Running Loop=1
2025-05-05T16:22:38.213Z,1746462158.213 [Default:CheckIn:D] Stopped
2025-05-05T16:22:38.213Z,1746462158.213 [Default:CheckIn:E] Running Loop=1
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.934857 min
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn:E] Stopped
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn] Stopped
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn](INFO): Running loop #2
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn] Running Loop=2
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T16:22:38.621Z,1746462158.621 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T16:23:25.904Z,1746462205.904 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2025-05-05T16:23:25.905Z,1746462205.905 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:23:25.940Z,1746462205.940 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:23:26.319Z,1746462206.319 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:23:26.319Z,1746462206.319 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2025-05-05T16:25:26.697Z,1746462326.697 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-05T16:25:26.697Z,1746462326.697 [NAL9602] Data Fault, FailCount= 3
2025-05-05T16:25:26.697Z,1746462326.697 [NAL9602](ERROR): Data Fault
2025-05-05T16:25:26.739Z,1746462326.739 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-05T16:25:27.101Z,1746462327.101 [NAL9602](INFO): Powering down
2025-05-05T16:25:27.929Z,1746462327.929 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-05T16:25:27.929Z,1746462327.929 [NAL9602] No Fault, FailCount= 3
2025-05-05T16:25:57.402Z,1746462357.402 [NAL9602](INFO): Powering up NAL9602
2025-05-05T16:26:08.309Z,1746462368.309 [NAL9602](INFO): NAL9602 initialized
2025-05-05T16:26:26.908Z,1746462386.908 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2025-05-05T16:26:26.908Z,1746462386.908 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:26:26.919Z,1746462386.919 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:26:27.345Z,1746462387.345 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:26:27.345Z,1746462387.345 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2025-05-05T16:27:38.811Z,1746462458.811 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-05T16:22:38.6Z
2025-05-05T16:27:38.811Z,1746462458.811 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T16:27:38.811Z,1746462458.811 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T16:27:49.319Z,1746462469.319 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250505T155304/Courier0016.lzma
2025-05-05T16:27:50.321Z,1746462470.321 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0016.lzma.bak
2025-05-05T16:27:50.321Z,1746462470.321 [DataOverHttps](INFO): SBD MOMSN=24773216
2025-05-05T16:28:06.019Z,1746462486.019 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20250505T155304/Express0017.lzma
2025-05-05T16:28:07.021Z,1746462487.021 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0017.lzma.bak
2025-05-05T16:28:07.021Z,1746462487.021 [DataOverHttps](INFO): SBD MOMSN=24773218
2025-05-05T16:28:08.361Z,1746462488.361 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T16:28:08.362Z,1746462488.362 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T16:28:08.362Z,1746462488.362 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:29:27.932Z,1746462567.932 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2025-05-05T16:29:27.932Z,1746462567.932 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:29:27.964Z,1746462567.964 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:29:28.347Z,1746462568.347 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:29:28.347Z,1746462568.347 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2025-05-05T16:32:25.797Z,1746462745.797 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 100 cubic_centimeter
2025-05-05T16:32:25.809Z,1746462745.809 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2025-05-05T16:32:26.176Z,1746462746.176 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-05-05T16:32:28.988Z,1746462748.988 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2025-05-05T16:32:28.988Z,1746462748.988 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-05T16:32:28.999Z,1746462748.999 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-05T16:32:29.481Z,1746462749.481 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-05T16:32:29.481Z,1746462749.481 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2025-05-05T16:33:08.985Z,1746462788.985 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T16:33:08.985Z,1746462788.985 [Default:CheckIn:C.Wait] Stopped
2025-05-05T16:33:08.985Z,1746462788.985 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:33:08.985Z,1746462788.985 [Default:CheckIn:D] Running Loop=1
2025-05-05T16:33:09.413Z,1746462789.413 [Default:CheckIn:D] Stopped
2025-05-05T16:33:09.413Z,1746462789.413 [Default:CheckIn:E] Running Loop=1
2025-05-05T16:33:09.818Z,1746462789.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.454867 min
2025-05-05T16:33:09.818Z,1746462789.818 [Default:CheckIn:E] Stopped
2025-05-05T16:33:09.818Z,1746462789.818 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T16:33:09.818Z,1746462789.818 [Default:CheckIn] Stopped
2025-05-05T16:33:09.818Z,1746462789.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T16:33:09.818Z,1746462789.818 [Default:CheckIn](INFO): Running loop #3
2025-05-05T16:33:09.818Z,1746462789.818 [Default:CheckIn] Running Loop=3
2025-05-05T16:33:09.819Z,1746462789.819 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T16:33:09.819Z,1746462789.819 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T16:34:39.883Z,1746462879.883 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163439.00,A,3648.16460,N,12147.28586,W,0.194,0.00,050525,,,A*71
2025-05-05T16:34:39.886Z,1746462879.886 [NAL9602](INFO): GPS fix at 20250505T163439: (36.802743, -121.788098)
2025-05-05T16:34:39.897Z,1746462879.897 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T16:34:39.897Z,1746462879.897 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T16:34:44.939Z,1746462884.939 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20250505T155304/Courier0019.lzma
2025-05-05T16:34:45.944Z,1746462885.944 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0019.lzma.bak
2025-05-05T16:34:45.945Z,1746462885.945 [DataOverHttps](INFO): SBD MOMSN=24773235
2025-05-05T16:35:01.812Z,1746462901.812 [DataOverHttps](INFO): Sending 410 bytes from file Logs/20250505T155304/Express0020.lzma
2025-05-05T16:35:02.814Z,1746462902.814 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0020.lzma.bak
2025-05-05T16:35:02.814Z,1746462902.814 [DataOverHttps](INFO): SBD MOMSN=24773238
2025-05-05T16:35:03.832Z,1746462903.832 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T16:35:03.832Z,1746462903.832 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T16:35:03.832Z,1746462903.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:35:12.297Z,1746462912.297 [NAL9602](INFO): Powering down
2025-05-05T16:40:04.452Z,1746463204.452 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T16:40:04.452Z,1746463204.452 [Default:CheckIn:C.Wait] Stopped
2025-05-05T16:40:04.452Z,1746463204.452 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:40:04.453Z,1746463204.453 [Default:CheckIn:D] Running Loop=1
2025-05-05T16:40:04.862Z,1746463204.862 [Default:CheckIn:D] Stopped
2025-05-05T16:40:04.862Z,1746463204.862 [Default:CheckIn:E] Running Loop=1
2025-05-05T16:40:05.254Z,1746463205.254 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.379012 min
2025-05-05T16:40:05.254Z,1746463205.254 [Default:CheckIn:E] Stopped
2025-05-05T16:40:05.254Z,1746463205.254 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T16:40:05.254Z,1746463205.254 [Default:CheckIn] Stopped
2025-05-05T16:40:05.254Z,1746463205.254 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T16:40:05.255Z,1746463205.255 [Default:CheckIn](INFO): Running loop #4
2025-05-05T16:40:05.255Z,1746463205.255 [Default:CheckIn] Running Loop=4
2025-05-05T16:40:05.255Z,1746463205.255 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T16:40:05.255Z,1746463205.255 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T16:40:06.056Z,1746463206.056 [NAL9602](INFO): Powering up
2025-05-05T16:40:16.965Z,1746463216.965 [NAL9602](INFO): NAL9602 initialized
2025-05-05T16:41:21.607Z,1746463281.607 [NAL9602](INFO): SBD MO Status=2, MOMSN=19308, MT Status=2, MTMSN=0
2025-05-05T16:41:21.608Z,1746463281.608 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-05T16:45:05.447Z,1746463505.447 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-05T16:40:05.3Z
2025-05-05T16:45:05.447Z,1746463505.447 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T16:45:05.448Z,1746463505.448 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T16:45:08.668Z,1746463508.668 [NAL9602](INFO): SBD MO Status=0, MOMSN=19308, MT Status=0, MTMSN=0
2025-05-05T16:45:08.668Z,1746463508.668 [NAL9602](INFO): No messages in MT queue
2025-05-05T16:45:12.571Z,1746463512.571 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250505T155304/Courier0022.lzma
2025-05-05T16:45:13.574Z,1746463513.574 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0022.lzma.bak
2025-05-05T16:45:13.574Z,1746463513.574 [DataOverHttps](IMPORTANT): SBD MOMSN=24773264, MTMSN=20250505T164512
2025-05-05T16:45:21.051Z,1746463521.051 [DataOverHttps](INFO): Received command: maintain clear
2025-05-05T16:45:21.113Z,1746463521.113 [CommandExec](IMPORTANT): got command maintain clear
2025-05-05T16:45:21.229Z,1746463521.229 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-05-05T16:45:29.591Z,1746463529.591 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20250505T155304/Express0023.lzma
2025-05-05T16:45:30.593Z,1746463530.593 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0023.lzma.bak
2025-05-05T16:45:30.593Z,1746463530.593 [DataOverHttps](INFO): SBD MOMSN=24773267
2025-05-05T16:45:39.368Z,1746463539.368 [NAL9602](INFO): Powering down
2025-05-05T16:45:49.651Z,1746463549.651 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250505T155304/Courier0025.lzma
2025-05-05T16:45:50.653Z,1746463550.653 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0025.lzma.bak
2025-05-05T16:45:50.653Z,1746463550.653 [DataOverHttps](INFO): SBD MOMSN=24773271
2025-05-05T16:46:06.623Z,1746463566.623 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20250505T155304/Express0026.lzma
2025-05-05T16:46:07.625Z,1746463567.625 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0026.lzma.bak
2025-05-05T16:46:07.625Z,1746463567.625 [DataOverHttps](INFO): SBD MOMSN=24773273
2025-05-05T16:46:08.914Z,1746463568.914 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T16:46:08.931Z,1746463568.931 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T16:46:08.931Z,1746463568.931 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:51:09.553Z,1746463869.553 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T16:51:09.554Z,1746463869.554 [Default:CheckIn:C.Wait] Stopped
2025-05-05T16:51:09.554Z,1746463869.554 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:51:09.554Z,1746463869.554 [Default:CheckIn:D] Running Loop=1
2025-05-05T16:51:09.958Z,1746463869.958 [Default:CheckIn:D] Stopped
2025-05-05T16:51:09.958Z,1746463869.958 [Default:CheckIn:E] Running Loop=1
2025-05-05T16:51:10.366Z,1746463870.366 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.463953 min
2025-05-05T16:51:10.366Z,1746463870.366 [Default:CheckIn:E] Stopped
2025-05-05T16:51:10.367Z,1746463870.367 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T16:51:10.367Z,1746463870.367 [Default:CheckIn] Stopped
2025-05-05T16:51:10.367Z,1746463870.367 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T16:51:10.367Z,1746463870.367 [Default:CheckIn](INFO): Running loop #5
2025-05-05T16:51:10.367Z,1746463870.367 [Default:CheckIn] Running Loop=5
2025-05-05T16:51:10.367Z,1746463870.367 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T16:51:10.367Z,1746463870.367 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T16:51:11.157Z,1746463871.157 [NAL9602](INFO): Powering up
2025-05-05T16:51:22.069Z,1746463882.069 [NAL9602](INFO): NAL9602 initialized
2025-05-05T16:51:22.874Z,1746463882.874 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-05T16:51:22.874Z,1746463882.874 [NAL9602] Data Fault, FailCount= 1
2025-05-05T16:51:22.874Z,1746463882.874 [NAL9602](ERROR): Data Fault
2025-05-05T16:51:22.894Z,1746463882.894 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-05T16:51:23.280Z,1746463883.280 [NAL9602](INFO): Powering down
2025-05-05T16:51:24.129Z,1746463884.129 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-05T16:51:24.129Z,1746463884.129 [NAL9602] No Fault, FailCount= 1
2025-05-05T16:51:53.577Z,1746463913.577 [NAL9602](INFO): Powering up NAL9602
2025-05-05T16:52:04.490Z,1746463924.490 [NAL9602](INFO): NAL9602 initialized
2025-05-05T16:52:19.840Z,1746463939.840 [NAL9602](INFO): SBD MO Status=0, MOMSN=19309, MT Status=0, MTMSN=0
2025-05-05T16:52:19.840Z,1746463939.840 [NAL9602](INFO): No messages in MT queue
2025-05-05T16:53:04.692Z,1746463984.692 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165303.00,A,3648.15346,N,12147.22200,W,0.350,323.83,050525,,,A*79
2025-05-05T16:53:04.694Z,1746463984.694 [NAL9602](INFO): GPS fix at 20250505T165303: (36.802558, -121.787033)
2025-05-05T16:53:04.705Z,1746463984.705 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T16:53:04.705Z,1746463984.705 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T16:53:11.655Z,1746463991.655 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250505T155304/Courier0028.lzma
2025-05-05T16:53:12.657Z,1746463992.657 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0028.lzma.bak
2025-05-05T16:53:12.657Z,1746463992.657 [DataOverHttps](INFO): SBD MOMSN=24773290
2025-05-05T16:53:28.851Z,1746464008.851 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20250505T155304/Express0029.lzma
2025-05-05T16:53:29.873Z,1746464009.873 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0029.lzma.bak
2025-05-05T16:53:29.873Z,1746464009.873 [DataOverHttps](INFO): SBD MOMSN=24773293
2025-05-05T16:53:30.953Z,1746464010.953 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T16:53:30.953Z,1746464010.953 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T16:53:30.954Z,1746464010.954 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T16:53:37.408Z,1746464017.408 [NAL9602](INFO): Powering down
2025-05-05T16:58:31.697Z,1746464311.697 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T16:58:31.697Z,1746464311.697 [Default:CheckIn:C.Wait] Stopped
2025-05-05T16:58:31.697Z,1746464311.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T16:58:31.698Z,1746464311.698 [Default:CheckIn:D] Running Loop=1
2025-05-05T16:58:31.978Z,1746464311.978 [Default:CheckIn:D] Stopped
2025-05-05T16:58:31.978Z,1746464311.978 [Default:CheckIn:E] Running Loop=1
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.830941 min
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn:E] Stopped
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn] Stopped
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn](INFO): Running loop #6
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn] Running Loop=6
2025-05-05T16:58:32.390Z,1746464312.390 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T16:58:32.391Z,1746464312.391 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T16:58:33.180Z,1746464313.180 [NAL9602](INFO): Powering up
2025-05-05T16:58:44.090Z,1746464324.090 [NAL9602](INFO): NAL9602 initialized
2025-05-05T16:58:59.039Z,1746464339.039 [NAL9602](INFO): SBD MO Status=0, MOMSN=19310, MT Status=0, MTMSN=0
2025-05-05T16:58:59.039Z,1746464339.039 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:00:13.782Z,1746464413.782 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170012.00,A,3648.15407,N,12147.22444,W,0.000,80.51,050525,,,A*49
2025-05-05T17:00:13.785Z,1746464413.785 [NAL9602](INFO): GPS fix at 20250505T170012: (36.802568, -121.787074)
2025-05-05T17:00:13.795Z,1746464413.795 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:00:13.796Z,1746464413.796 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:00:20.847Z,1746464420.847 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250505T155304/Courier0031.lzma
2025-05-05T17:00:21.849Z,1746464421.849 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0031.lzma.bak
2025-05-05T17:00:21.849Z,1746464421.849 [DataOverHttps](INFO): SBD MOMSN=24773311
2025-05-05T17:00:37.392Z,1746464437.392 [CommandExec](IMPORTANT): got command failComponent
2025-05-05T17:00:37.392Z,1746464437.392 [CommandExec](IMPORTANT): Failed components:
2025-05-05T17:00:37.392Z,1746464437.392 [CommandExec](IMPORTANT): No failed Components.
2025-05-05T17:00:38.071Z,1746464438.071 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250505T155304/Express0032.lzma
2025-05-05T17:00:39.073Z,1746464439.073 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0032.lzma.bak
2025-05-05T17:00:39.073Z,1746464439.073 [DataOverHttps](INFO): SBD MOMSN=24773314
2025-05-05T17:00:39.480Z,1746464439.480 [CommandExec](IMPORTANT): got command ibit
2025-05-05T17:00:39.652Z,1746464439.652 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-05-05T17:00:39.652Z,1746464439.652 [IBIT](IMPORTANT): Beginning control surface checks.
2025-05-05T17:00:39.660Z,1746464439.660 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-05T17:00:41.256Z,1746464441.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170039.00,A,3648.15392,N,12147.22062,W,0.214,80.51,050525,,,A*4C
2025-05-05T17:00:41.258Z,1746464441.258 [NAL9602](INFO): GPS fix at 20250505T170039: (36.802565, -121.787010)
2025-05-05T17:00:43.674Z,1746464443.674 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170041.00,A,3648.15392,N,12147.22058,W,0.058,80.51,050525,,,A*40
2025-05-05T17:00:43.677Z,1746464443.677 [NAL9602](INFO): GPS fix at 20250505T170041: (36.802565, -121.787010)
2025-05-05T17:00:44.283Z,1746464444.283 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007143
CHAN A1 (24V): 0.000262
CHAN A2 (12V): -0.005537
CHAN A3 (5V): -0.002820
CHAN B0 (3.3V): -0.001249
CHAN B1 (3.15aV): -0.001299
CHAN B2 (3.15bV): -0.001185
CHAN B3 (GND): -0.000721
OPEN: 0.004962
Full Scale: +/- 1 mA
2025-05-05T17:00:46.922Z,1746464446.922 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170045.00,A,3648.15389,N,12147.22030,W,0.136,80.51,050525,,,A*49
2025-05-05T17:00:46.925Z,1746464446.925 [NAL9602](INFO): GPS fix at 20250505T170045: (36.802565, -121.787005)
2025-05-05T17:00:49.748Z,1746464449.748 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170048.00,A,3648.15381,N,12147.22007,W,0.019,80.51,050525,,,A*44
2025-05-05T17:00:49.750Z,1746464449.750 [NAL9602](INFO): GPS fix at 20250505T170048: (36.802563, -121.787001)
2025-05-05T17:00:52.982Z,1746464452.982 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170051.00,A,3648.15371,N,12147.21977,W,0.214,80.51,050525,,,A*41
2025-05-05T17:00:52.985Z,1746464452.985 [NAL9602](INFO): GPS fix at 20250505T170051: (36.802562, -121.786996)
2025-05-05T17:00:55.807Z,1746464455.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170054.00,A,3648.15378,N,12147.21987,W,0.000,80.51,050525,,,A*45
2025-05-05T17:00:55.810Z,1746464455.810 [NAL9602](INFO): GPS fix at 20250505T170054: (36.802563, -121.786998)
2025-05-05T17:00:59.046Z,1746464459.046 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170057.00,A,3648.15385,N,12147.22001,W,0.078,80.51,050525,,,A*4F
2025-05-05T17:00:59.049Z,1746464459.049 [NAL9602](INFO): GPS fix at 20250505T170057: (36.802564, -121.787000)
2025-05-05T17:01:01.870Z,1746464461.870 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170100.00,A,3648.15390,N,12147.22018,W,0.058,80.51,050525,,,A*42
2025-05-05T17:01:01.873Z,1746464461.873 [NAL9602](INFO): GPS fix at 20250505T170100: (36.802565, -121.787003)
2025-05-05T17:01:04.703Z,1746464464.703 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170103.00,A,3648.15386,N,12147.22016,W,0.039,80.51,050525,,,A*4F
2025-05-05T17:01:04.705Z,1746464464.705 [NAL9602](INFO): GPS fix at 20250505T170103: (36.802564, -121.787003)
2025-05-05T17:01:07.930Z,1746464467.930 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170106.00,A,3648.15375,N,12147.22036,W,0.058,80.51,050525,,,A*43
2025-05-05T17:01:07.934Z,1746464467.934 [NAL9602](INFO): GPS fix at 20250505T170106: (36.802563, -121.787006)
2025-05-05T17:01:10.767Z,1746464470.767 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170109.00,A,3648.15359,N,12147.22025,W,0.058,80.51,050525,,,A*40
2025-05-05T17:01:10.769Z,1746464470.769 [NAL9602](INFO): GPS fix at 20250505T170109: (36.802560, -121.787004)
2025-05-05T17:01:13.993Z,1746464473.993 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170112.00,A,3648.15352,N,12147.22017,W,0.097,80.51,050525,,,A*43
2025-05-05T17:01:13.996Z,1746464473.996 [NAL9602](INFO): GPS fix at 20250505T170112: (36.802559, -121.787003)
2025-05-05T17:01:16.843Z,1746464476.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170115.00,A,3648.15347,N,12147.21999,W,0.019,80.51,050525,,,A*4A
2025-05-05T17:01:16.846Z,1746464476.846 [NAL9602](INFO): GPS fix at 20250505T170115: (36.802558, -121.787000)
2025-05-05T17:01:20.050Z,1746464480.050 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170118.00,A,3648.15346,N,12147.21980,W,0.019,80.51,050525,,,A*4E
2025-05-05T17:01:20.053Z,1746464480.053 [NAL9602](INFO): GPS fix at 20250505T170118: (36.802558, -121.786997)
2025-05-05T17:01:22.876Z,1746464482.876 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170121.00,A,3648.15346,N,12147.21967,W,0.097,80.51,050525,,,A*4B
2025-05-05T17:01:22.878Z,1746464482.878 [NAL9602](INFO): GPS fix at 20250505T170121: (36.802558, -121.786995)
2025-05-05T17:01:25.706Z,1746464485.706 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170124.00,A,3648.15336,N,12147.21941,W,0.078,80.51,050525,,,A*4C
2025-05-05T17:01:25.709Z,1746464485.709 [NAL9602](INFO): GPS fix at 20250505T170124: (36.802556, -121.786990)
2025-05-05T17:01:26.165Z,1746464486.165 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802555 Longitude: -121.786987
2025-05-05T17:01:26.549Z,1746464486.549 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.690001
2025-05-05T17:01:26.549Z,1746464486.549 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-05-05T17:01:26.550Z,1746464486.550 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-05-05T17:01:26.941Z,1746464486.941 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-05-05T17:01:26.941Z,1746464486.941 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-05-05T17:01:26.942Z,1746464486.942 [IBIT](IMPORTANT): Pressure:9.874759 PSI
2025-05-05T17:01:26.942Z,1746464486.942 [IBIT](IMPORTANT): Humidity:10.749603 %
2025-05-05T17:01:27.357Z,1746464487.357 [IBIT](IMPORTANT): Vehicle Pitch:1.311672 degrees
2025-05-05T17:01:27.358Z,1746464487.358 [IBIT](IMPORTANT): Vehicle Roll:6.717110 degrees
2025-05-05T17:01:27.358Z,1746464487.358 [IBIT](IMPORTANT): Vehicle Heading:207.050308 degrees
2025-05-05T17:01:27.776Z,1746464487.776 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-05-05T17:01:27.776Z,1746464487.776 [IBIT](IMPORTANT): buoyancyNeutral: 204.697006 cc
2025-05-05T17:01:27.777Z,1746464487.777 [IBIT](IMPORTANT): massDefault: 2.546212 cm
2025-05-05T17:01:27.777Z,1746464487.777 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2025-05-05T17:01:27.777Z,1746464487.777 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-05-05T17:01:27.777Z,1746464487.777 [IBIT](IMPORTANT): IBIT PASSED
2025-05-05T17:01:28.158Z,1746464488.158 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:01:28.158Z,1746464488.158 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:01:28.158Z,1746464488.158 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:01:58.425Z,1746464518.425 [NAL9602](INFO): Powering down
2025-05-05T17:03:52.332Z,1746464632.332 [CommandExec](IMPORTANT): got command failComponent
2025-05-05T17:03:52.332Z,1746464632.332 [CommandExec](IMPORTANT): Failed components:
2025-05-05T17:03:52.332Z,1746464632.332 [CommandExec](IMPORTANT): No failed Components.
2025-05-05T17:06:28.771Z,1746464788.771 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T17:06:28.771Z,1746464788.771 [Default:CheckIn:C.Wait] Stopped
2025-05-05T17:06:28.771Z,1746464788.771 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T17:06:28.771Z,1746464788.771 [Default:CheckIn:D] Running Loop=1
2025-05-05T17:06:29.179Z,1746464789.179 [Default:CheckIn:D] Stopped
2025-05-05T17:06:29.179Z,1746464789.179 [Default:CheckIn:E] Running Loop=1
2025-05-05T17:06:29.576Z,1746464789.576 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.784294 min
2025-05-05T17:06:29.576Z,1746464789.576 [Default:CheckIn:E] Stopped
2025-05-05T17:06:29.576Z,1746464789.576 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T17:06:29.576Z,1746464789.576 [Default:CheckIn] Stopped
2025-05-05T17:06:29.576Z,1746464789.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T17:06:29.576Z,1746464789.576 [Default:CheckIn](INFO): Running loop #7
2025-05-05T17:06:29.576Z,1746464789.576 [Default:CheckIn] Running Loop=7
2025-05-05T17:06:29.577Z,1746464789.577 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T17:06:29.577Z,1746464789.577 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T17:06:30.439Z,1746464790.439 [NAL9602](INFO): Powering up
2025-05-05T17:06:41.286Z,1746464801.286 [NAL9602](INFO): NAL9602 initialized
2025-05-05T17:07:07.543Z,1746464827.543 [NAL9602](INFO): SBD MO Status=0, MOMSN=19311, MT Status=0, MTMSN=0
2025-05-05T17:07:07.543Z,1746464827.543 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:08:08.154Z,1746464888.154 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-05-05T17:08:08.161Z,1746464888.161 [BPC1](INFO): Received data from all battery sticks.
2025-05-05T17:11:16.812Z,1746465076.812 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171116.00,A,3648.16494,N,12147.22167,W,0.778,185.20,050525,,,A*7A
2025-05-05T17:11:16.814Z,1746465076.814 [NAL9602](INFO): GPS fix at 20250505T171116: (36.802749, -121.787028)
2025-05-05T17:11:16.825Z,1746465076.825 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:11:16.825Z,1746465076.825 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:11:24.291Z,1746465084.291 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250505T155304/Courier0034.lzma
2025-05-05T17:11:25.293Z,1746465085.293 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0034.lzma.bak
2025-05-05T17:11:25.293Z,1746465085.293 [DataOverHttps](INFO): SBD MOMSN=24773336
2025-05-05T17:11:41.190Z,1746465101.190 [DataOverHttps](INFO): Sending 1082 bytes from file Logs/20250505T155304/Express0035.lzma
2025-05-05T17:11:42.189Z,1746465102.189 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0035.lzma.bak
2025-05-05T17:11:42.189Z,1746465102.189 [DataOverHttps](INFO): SBD MOMSN=24773339
2025-05-05T17:11:43.511Z,1746465103.511 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:11:43.511Z,1746465103.511 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:11:43.520Z,1746465103.520 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:11:49.605Z,1746465109.605 [NAL9602](INFO): Powering down
2025-05-05T17:13:37.261Z,1746465217.261 [DataOverHttps](IMPORTANT): SBD MTMSN=20250505T171336
2025-05-05T17:13:47.207Z,1746465227.207 [DataOverHttps](INFO): Received command: failComponent
2025-05-05T17:13:47.281Z,1746465227.281 [CommandExec](IMPORTANT): got command failComponent
2025-05-05T17:13:47.281Z,1746465227.281 [CommandExec](IMPORTANT): Failed components:
2025-05-05T17:13:47.281Z,1746465227.281 [CommandExec](IMPORTANT): No failed Components.
2025-05-05T17:16:44.174Z,1746465404.174 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T17:16:44.174Z,1746465404.174 [Default:CheckIn:C.Wait] Stopped
2025-05-05T17:16:44.174Z,1746465404.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T17:16:44.174Z,1746465404.174 [Default:CheckIn:D] Running Loop=1
2025-05-05T17:16:44.578Z,1746465404.578 [Default:CheckIn:D] Stopped
2025-05-05T17:16:44.578Z,1746465404.578 [Default:CheckIn:E] Running Loop=1
2025-05-05T17:16:44.983Z,1746465404.983 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.040938 min
2025-05-05T17:16:44.983Z,1746465404.983 [Default:CheckIn:E] Stopped
2025-05-05T17:16:44.983Z,1746465404.983 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T17:16:44.983Z,1746465404.983 [Default:CheckIn] Stopped
2025-05-05T17:16:44.983Z,1746465404.983 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T17:16:44.983Z,1746465404.983 [Default:CheckIn](INFO): Running loop #8
2025-05-05T17:16:44.984Z,1746465404.984 [Default:CheckIn] Running Loop=8
2025-05-05T17:16:44.984Z,1746465404.984 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T17:16:44.984Z,1746465404.984 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T17:16:45.784Z,1746465405.784 [NAL9602](INFO): Powering up
2025-05-05T17:16:56.689Z,1746465416.689 [NAL9602](INFO): NAL9602 initialized
2025-05-05T17:17:10.424Z,1746465430.424 [NAL9602](INFO): SBD MO Status=0, MOMSN=19312, MT Status=0, MTMSN=0
2025-05-05T17:17:10.424Z,1746465430.424 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:19:22.950Z,1746465562.950 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171921.00,A,3648.15652,N,12147.22088,W,0.039,0.00,050525,,,A*71
2025-05-05T17:19:22.953Z,1746465562.953 [NAL9602](INFO): GPS fix at 20250505T171921: (36.802609, -121.787015)
2025-05-05T17:19:22.962Z,1746465562.962 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:19:22.963Z,1746465562.963 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:19:30.267Z,1746465570.267 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250505T155304/Courier0037.lzma
2025-05-05T17:19:31.269Z,1746465571.269 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0037.lzma.bak
2025-05-05T17:19:31.269Z,1746465571.269 [DataOverHttps](INFO): SBD MOMSN=24773411
2025-05-05T17:19:49.964Z,1746465589.964 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20250505T155304/Express0038.lzma
2025-05-05T17:19:50.965Z,1746465590.965 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0038.lzma.bak
2025-05-05T17:19:50.965Z,1746465590.965 [DataOverHttps](INFO): SBD MOMSN=24773414
2025-05-05T17:19:52.114Z,1746465592.114 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:19:52.114Z,1746465592.114 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:19:52.114Z,1746465592.114 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:19:55.324Z,1746465595.324 [NAL9602](INFO): Powering down
2025-05-05T17:24:52.741Z,1746465892.741 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T17:24:52.741Z,1746465892.741 [Default:CheckIn:C.Wait] Stopped
2025-05-05T17:24:52.741Z,1746465892.741 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T17:24:52.741Z,1746465892.741 [Default:CheckIn:D] Running Loop=1
2025-05-05T17:24:53.123Z,1746465893.123 [Default:CheckIn:D] Stopped
2025-05-05T17:24:53.123Z,1746465893.123 [Default:CheckIn:E] Running Loop=1
2025-05-05T17:24:53.534Z,1746465893.534 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.183358 min
2025-05-05T17:24:53.534Z,1746465893.534 [Default:CheckIn:E] Stopped
2025-05-05T17:24:53.534Z,1746465893.534 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T17:24:53.534Z,1746465893.534 [Default:CheckIn] Stopped
2025-05-05T17:24:53.534Z,1746465893.534 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T17:24:53.535Z,1746465893.535 [Default:CheckIn](INFO): Running loop #9
2025-05-05T17:24:53.535Z,1746465893.535 [Default:CheckIn] Running Loop=9
2025-05-05T17:24:53.535Z,1746465893.535 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T17:24:53.536Z,1746465893.536 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T17:24:54.332Z,1746465894.332 [NAL9602](INFO): Powering up
2025-05-05T17:25:05.234Z,1746465905.234 [NAL9602](INFO): NAL9602 initialized
2025-05-05T17:25:16.970Z,1746465916.970 [NAL9602](INFO): SBD MO Status=0, MOMSN=19313, MT Status=0, MTMSN=0
2025-05-05T17:25:16.970Z,1746465916.970 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:26:49.877Z,1746466009.877 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172648.00,A,3648.15217,N,12147.22196,W,0.680,0.00,050525,,,A*7D
2025-05-05T17:26:49.879Z,1746466009.879 [NAL9602](INFO): GPS fix at 20250505T172648: (36.802536, -121.787033)
2025-05-05T17:26:49.889Z,1746466009.889 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:26:49.889Z,1746466009.889 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:26:57.651Z,1746466017.651 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250505T155304/Courier0043.lzma
2025-05-05T17:26:58.653Z,1746466018.653 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0043.lzma.bak
2025-05-05T17:26:58.653Z,1746466018.653 [DataOverHttps](INFO): SBD MOMSN=24773435
2025-05-05T17:27:14.527Z,1746466034.527 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250505T155304/Express0044.lzma
2025-05-05T17:27:15.529Z,1746466035.529 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0044.lzma.bak
2025-05-05T17:27:15.530Z,1746466035.530 [DataOverHttps](INFO): SBD MOMSN=24773438
2025-05-05T17:27:16.566Z,1746466036.566 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:27:16.566Z,1746466036.566 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:27:16.566Z,1746466036.566 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:27:22.216Z,1746466042.216 [NAL9602](INFO): Powering down
2025-05-05T17:32:17.210Z,1746466337.210 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T17:32:17.210Z,1746466337.210 [Default:CheckIn:C.Wait] Stopped
2025-05-05T17:32:17.210Z,1746466337.210 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T17:32:17.210Z,1746466337.210 [Default:CheckIn:D] Running Loop=1
2025-05-05T17:32:17.606Z,1746466337.606 [Default:CheckIn:D] Stopped
2025-05-05T17:32:17.606Z,1746466337.606 [Default:CheckIn:E] Running Loop=1
2025-05-05T17:32:18.011Z,1746466338.011 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.591406 min
2025-05-05T17:32:18.011Z,1746466338.011 [Default:CheckIn:E] Stopped
2025-05-05T17:32:18.011Z,1746466338.011 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T17:32:18.011Z,1746466338.011 [Default:CheckIn] Stopped
2025-05-05T17:32:18.012Z,1746466338.012 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T17:32:18.012Z,1746466338.012 [Default:CheckIn](INFO): Running loop #10
2025-05-05T17:32:18.012Z,1746466338.012 [Default:CheckIn] Running Loop=10
2025-05-05T17:32:18.012Z,1746466338.012 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T17:32:18.012Z,1746466338.012 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T17:32:18.816Z,1746466338.816 [NAL9602](INFO): Powering up
2025-05-05T17:32:29.719Z,1746466349.719 [NAL9602](INFO): NAL9602 initialized
2025-05-05T17:32:55.978Z,1746466375.978 [NAL9602](INFO): SBD MO Status=0, MOMSN=19314, MT Status=0, MTMSN=0
2025-05-05T17:32:55.978Z,1746466375.978 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:33:37.998Z,1746466417.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173336.00,A,3648.14657,N,12147.22130,W,0.428,0.00,050525,,,A*7D
2025-05-05T17:33:37.000Z,1746466418.000 [NAL9602](INFO): GPS fix at 20250505T173336: (36.802443, -121.787022)
2025-05-05T17:33:38.010Z,1746466418.010 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:33:38.010Z,1746466418.010 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:33:45.711Z,1746466425.711 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250505T155304/Courier0046.lzma
2025-05-05T17:33:46.713Z,1746466426.713 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0046.lzma.bak
2025-05-05T17:33:46.713Z,1746466426.713 [DataOverHttps](INFO): SBD MOMSN=24773449
2025-05-05T17:34:05.479Z,1746466445.479 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250505T155304/Express0047.lzma
2025-05-05T17:34:06.481Z,1746466446.481 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0047.lzma.bak
2025-05-05T17:34:06.481Z,1746466446.481 [DataOverHttps](INFO): SBD MOMSN=24773452
2025-05-05T17:34:07.548Z,1746466447.548 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:34:07.548Z,1746466447.548 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:34:07.548Z,1746466447.548 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:34:10.360Z,1746466450.360 [NAL9602](INFO): Powering down
2025-05-05T17:39:08.157Z,1746466748.157 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T17:39:08.157Z,1746466748.157 [Default:CheckIn:C.Wait] Stopped
2025-05-05T17:39:08.157Z,1746466748.157 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T17:39:08.157Z,1746466748.157 [Default:CheckIn:D] Running Loop=1
2025-05-05T17:39:08.554Z,1746466748.554 [Default:CheckIn:D] Stopped
2025-05-05T17:39:08.554Z,1746466748.554 [Default:CheckIn:E] Running Loop=1
2025-05-05T17:39:08.966Z,1746466748.966 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.440552 min
2025-05-05T17:39:08.966Z,1746466748.966 [Default:CheckIn:E] Stopped
2025-05-05T17:39:08.966Z,1746466748.966 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T17:39:08.966Z,1746466748.966 [Default:CheckIn] Stopped
2025-05-05T17:39:08.966Z,1746466748.966 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T17:39:08.966Z,1746466748.966 [Default:CheckIn](INFO): Running loop #11
2025-05-05T17:39:08.967Z,1746466748.967 [Default:CheckIn] Running Loop=11
2025-05-05T17:39:08.967Z,1746466748.967 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T17:39:08.967Z,1746466748.967 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T17:39:09.769Z,1746466749.769 [NAL9602](INFO): Powering up
2025-05-05T17:39:20.667Z,1746466760.667 [NAL9602](INFO): NAL9602 initialized
2025-05-05T17:40:07.530Z,1746466807.530 [NAL9602](INFO): SBD MO Status=2, MOMSN=19315, MT Status=2, MTMSN=0
2025-05-05T17:40:07.530Z,1746466807.530 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-05T17:40:48.339Z,1746466848.339 [NAL9602](INFO): SBD MO Status=2, MOMSN=19315, MT Status=2, MTMSN=0
2025-05-05T17:40:48.339Z,1746466848.339 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-05T17:41:02.072Z,1746466862.072 [NAL9602](INFO): SBD MO Status=2, MOMSN=19315, MT Status=2, MTMSN=0
2025-05-05T17:41:02.072Z,1746466862.072 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-05T17:41:10.153Z,1746466870.153 [NAL9602](INFO): SBD MO Status=0, MOMSN=19315, MT Status=0, MTMSN=0
2025-05-05T17:41:10.153Z,1746466870.153 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:41:11.363Z,1746466871.363 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174109.00,A,3648.15571,N,12147.22281,W,0.233,0.00,050525,,,A*77
2025-05-05T17:41:11.365Z,1746466871.365 [NAL9602](INFO): GPS fix at 20250505T174109: (36.802595, -121.787047)
2025-05-05T17:41:11.375Z,1746466871.375 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:41:11.375Z,1746466871.375 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:41:19.055Z,1746466879.055 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250505T155304/Courier0049.lzma
2025-05-05T17:41:20.057Z,1746466880.057 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0049.lzma.bak
2025-05-05T17:41:20.057Z,1746466880.057 [DataOverHttps](INFO): SBD MOMSN=24773474
2025-05-05T17:41:36.279Z,1746466896.279 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250505T155304/Express0050.lzma
2025-05-05T17:41:37.281Z,1746466897.281 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0050.lzma.bak
2025-05-05T17:41:37.281Z,1746466897.281 [DataOverHttps](INFO): SBD MOMSN=24773477
2025-05-05T17:41:38.440Z,1746466898.440 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:41:38.440Z,1746466898.440 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:41:38.440Z,1746466898.440 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:41:43.276Z,1746466903.276 [NAL9602](INFO): Powering down
2025-05-05T17:46:39.070Z,1746467199.070 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T17:46:39.071Z,1746467199.071 [Default:CheckIn:C.Wait] Stopped
2025-05-05T17:46:39.071Z,1746467199.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T17:46:39.071Z,1746467199.071 [Default:CheckIn:D] Running Loop=1
2025-05-05T17:46:39.478Z,1746467199.478 [Default:CheckIn:D] Stopped
2025-05-05T17:46:39.478Z,1746467199.478 [Default:CheckIn:E] Running Loop=1
2025-05-05T17:46:39.881Z,1746467199.881 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.955941 min
2025-05-05T17:46:39.881Z,1746467199.881 [Default:CheckIn:E] Stopped
2025-05-05T17:46:39.882Z,1746467199.882 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T17:46:39.882Z,1746467199.882 [Default:CheckIn] Stopped
2025-05-05T17:46:39.882Z,1746467199.882 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T17:46:39.882Z,1746467199.882 [Default:CheckIn](INFO): Running loop #12
2025-05-05T17:46:39.882Z,1746467199.882 [Default:CheckIn] Running Loop=12
2025-05-05T17:46:39.882Z,1746467199.882 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T17:46:39.882Z,1746467199.882 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T17:46:40.680Z,1746467200.680 [NAL9602](INFO): Powering up
2025-05-05T17:46:51.600Z,1746467211.600 [NAL9602](INFO): NAL9602 initialized
2025-05-05T17:47:23.507Z,1746467243.507 [NAL9602](INFO): SBD MO Status=2, MOMSN=19316, MT Status=2, MTMSN=0
2025-05-05T17:47:23.508Z,1746467243.508 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-05T17:48:18.066Z,1746467298.066 [NAL9602](INFO): SBD MO Status=0, MOMSN=19316, MT Status=0, MTMSN=0
2025-05-05T17:48:18.066Z,1746467298.066 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:48:19.275Z,1746467299.275 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174817.00,A,3648.15419,N,12147.22055,W,0.389,0.00,050525,,,A*75
2025-05-05T17:48:19.277Z,1746467299.277 [NAL9602](INFO): GPS fix at 20250505T174817: (36.802570, -121.787009)
2025-05-05T17:48:19.303Z,1746467299.303 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:48:19.304Z,1746467299.304 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:48:26.307Z,1746467306.307 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250505T155304/Courier0052.lzma
2025-05-05T17:48:27.309Z,1746467307.309 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0052.lzma.bak
2025-05-05T17:48:27.309Z,1746467307.309 [DataOverHttps](INFO): SBD MOMSN=24773493
2025-05-05T17:48:43.479Z,1746467323.479 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250505T155304/Express0053.lzma
2025-05-05T17:48:44.481Z,1746467324.481 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0053.lzma.bak
2025-05-05T17:48:44.481Z,1746467324.481 [DataOverHttps](INFO): SBD MOMSN=24773496
2025-05-05T17:48:45.542Z,1746467325.542 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:48:45.542Z,1746467325.542 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:48:45.542Z,1746467325.542 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:48:51.188Z,1746467331.188 [NAL9602](INFO): Powering down
2025-05-05T17:53:46.141Z,1746467626.141 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T17:53:46.141Z,1746467626.141 [Default:CheckIn:C.Wait] Stopped
2025-05-05T17:53:46.141Z,1746467626.141 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T17:53:46.142Z,1746467626.142 [Default:CheckIn:D] Running Loop=1
2025-05-05T17:53:46.542Z,1746467626.542 [Default:CheckIn:D] Stopped
2025-05-05T17:53:46.542Z,1746467626.542 [Default:CheckIn:E] Running Loop=1
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.073690 min
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn:E] Stopped
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn] Stopped
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn](INFO): Running loop #13
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn] Running Loop=13
2025-05-05T17:53:46.954Z,1746467626.954 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T17:53:46.955Z,1746467626.955 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T17:53:47.744Z,1746467627.744 [NAL9602](INFO): Powering up
2025-05-05T17:53:58.658Z,1746467638.658 [NAL9602](INFO): NAL9602 initialized
2025-05-05T17:54:22.488Z,1746467662.488 [NAL9602](INFO): SBD MO Status=0, MOMSN=19317, MT Status=0, MTMSN=0
2025-05-05T17:54:22.488Z,1746467662.488 [NAL9602](INFO): No messages in MT queue
2025-05-05T17:55:01.693Z,1746467701.693 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175500.00,A,3648.15094,N,12147.21930,W,0.156,0.00,050525,,,A*77
2025-05-05T17:55:01.695Z,1746467701.695 [NAL9602](INFO): GPS fix at 20250505T175500: (36.802516, -121.786988)
2025-05-05T17:55:01.705Z,1746467701.705 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T17:55:01.706Z,1746467701.706 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T17:55:09.507Z,1746467709.507 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250505T155304/Courier0055.lzma
2025-05-05T17:55:10.509Z,1746467710.509 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0055.lzma.bak
2025-05-05T17:55:10.509Z,1746467710.509 [DataOverHttps](INFO): SBD MOMSN=24773507
2025-05-05T17:55:26.315Z,1746467726.315 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250505T155304/Express0056.lzma
2025-05-05T17:55:27.317Z,1746467727.317 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0056.lzma.bak
2025-05-05T17:55:27.317Z,1746467727.317 [DataOverHttps](INFO): SBD MOMSN=24773510
2025-05-05T17:55:28.360Z,1746467728.360 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T17:55:28.361Z,1746467728.361 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T17:55:28.361Z,1746467728.361 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T17:55:34.405Z,1746467734.405 [NAL9602](INFO): Powering down
2025-05-05T18:00:28.984Z,1746468028.984 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T18:00:28.984Z,1746468028.984 [Default:CheckIn:C.Wait] Stopped
2025-05-05T18:00:28.984Z,1746468028.984 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T18:00:28.985Z,1746468028.985 [Default:CheckIn:D] Running Loop=1
2025-05-05T18:00:29.382Z,1746468029.382 [Default:CheckIn:D] Stopped
2025-05-05T18:00:29.382Z,1746468029.382 [Default:CheckIn:E] Running Loop=1
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.787671 min
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn:E] Stopped
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn] Stopped
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn](INFO): Running loop #14
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn] Running Loop=14
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T18:00:29.780Z,1746468029.780 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T18:00:30.577Z,1746468030.577 [NAL9602](INFO): Powering up
2025-05-05T18:00:41.485Z,1746468041.485 [NAL9602](INFO): NAL9602 initialized
2025-05-05T18:00:57.655Z,1746468057.655 [NAL9602](INFO): SBD MO Status=0, MOMSN=19318, MT Status=0, MTMSN=0
2025-05-05T18:00:57.655Z,1746468057.655 [NAL9602](INFO): No messages in MT queue
2025-05-05T18:02:31.788Z,1746468151.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180231.00,A,3648.33515,N,12147.12371,W,3.518,12.95,050525,,,A*4D
2025-05-05T18:02:31.790Z,1746468151.790 [NAL9602](INFO): GPS fix at 20250505T180231: (36.805586, -121.785395)
2025-05-05T18:02:31.800Z,1746468151.800 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T18:02:31.801Z,1746468151.801 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T18:02:39.340Z,1746468159.340 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250505T155304/Courier0058.lzma
2025-05-05T18:02:40.341Z,1746468160.341 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0058.lzma.bak
2025-05-05T18:02:40.341Z,1746468160.341 [DataOverHttps](INFO): SBD MOMSN=24773533
2025-05-05T18:02:56.247Z,1746468176.247 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250505T155304/Express0059.lzma
2025-05-05T18:02:57.249Z,1746468177.249 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0059.lzma.bak
2025-05-05T18:02:57.249Z,1746468177.249 [DataOverHttps](INFO): SBD MOMSN=24773536
2025-05-05T18:02:58.465Z,1746468178.465 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T18:02:58.466Z,1746468178.466 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T18:02:58.466Z,1746468178.466 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T18:03:04.500Z,1746468184.500 [NAL9602](INFO): Powering down
2025-05-05T18:07:59.049Z,1746468479.049 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T18:07:59.049Z,1746468479.049 [Default:CheckIn:C.Wait] Stopped
2025-05-05T18:07:59.049Z,1746468479.049 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T18:07:59.050Z,1746468479.050 [Default:CheckIn:D] Running Loop=1
2025-05-05T18:07:59.457Z,1746468479.457 [Default:CheckIn:D] Stopped
2025-05-05T18:07:59.457Z,1746468479.457 [Default:CheckIn:E] Running Loop=1
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.288932 min
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn:E] Stopped
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn] Stopped
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn](INFO): Running loop #15
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn] Running Loop=15
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T18:07:59.860Z,1746468479.860 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T18:08:00.660Z,1746468480.660 [NAL9602](INFO): Powering up
2025-05-05T18:08:11.566Z,1746468491.566 [NAL9602](INFO): NAL9602 initialized
2025-05-05T18:08:28.942Z,1746468508.942 [NAL9602](INFO): SBD MO Status=0, MOMSN=19319, MT Status=0, MTMSN=0
2025-05-05T18:08:28.942Z,1746468508.942 [NAL9602](INFO): No messages in MT queue
2025-05-05T18:13:00.034Z,1746468780.034 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-05T18:07:59.9Z
2025-05-05T18:13:00.034Z,1746468780.034 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T18:13:00.035Z,1746468780.035 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T18:13:07.455Z,1746468787.455 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250505T155304/Courier0061.lzma
2025-05-05T18:13:08.453Z,1746468788.453 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0061.lzma.bak
2025-05-05T18:13:08.453Z,1746468788.453 [DataOverHttps](INFO): SBD MOMSN=24773581
2025-05-05T18:13:28.371Z,1746468808.371 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20250505T155304/Express0062.lzma
2025-05-05T18:13:29.373Z,1746468809.373 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0062.lzma.bak
2025-05-05T18:13:29.373Z,1746468809.373 [DataOverHttps](INFO): SBD MOMSN=24773583
2025-05-05T18:13:30.735Z,1746468810.735 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T18:13:30.735Z,1746468810.735 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T18:13:30.735Z,1746468810.735 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T18:13:31.546Z,1746468811.546 [NAL9602](INFO): Powering down
2025-05-05T18:15:32.740Z,1746468932.740 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-05-05T18:15:32.743Z,1746468932.743 [BPC1](INFO): Received data from all battery sticks.
2025-05-05T18:18:31.338Z,1746469111.338 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-05T18:18:31.338Z,1746469111.338 [Default:CheckIn:C.Wait] Stopped
2025-05-05T18:18:31.338Z,1746469111.338 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-05T18:18:31.338Z,1746469111.338 [Default:CheckIn:D] Running Loop=1
2025-05-05T18:18:31.751Z,1746469111.751 [Default:CheckIn:D] Stopped
2025-05-05T18:18:31.751Z,1746469111.751 [Default:CheckIn:E] Running Loop=1
2025-05-05T18:18:32.146Z,1746469112.146 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.827165 min
2025-05-05T18:18:32.146Z,1746469112.146 [Default:CheckIn:E] Stopped
2025-05-05T18:18:32.146Z,1746469112.146 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-05T18:18:32.146Z,1746469112.146 [Default:CheckIn] Stopped
2025-05-05T18:18:32.146Z,1746469112.146 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-05T18:18:32.146Z,1746469112.146 [Default:CheckIn](INFO): Running loop #16
2025-05-05T18:18:32.147Z,1746469112.147 [Default:CheckIn] Running Loop=16
2025-05-05T18:18:32.147Z,1746469112.147 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-05T18:18:32.147Z,1746469112.147 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-05T18:18:32.942Z,1746469112.942 [NAL9602](INFO): Powering up
2025-05-05T18:18:43.849Z,1746469123.849 [NAL9602](INFO): NAL9602 initialized
2025-05-05T18:18:44.661Z,1746469124.661 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-05T18:18:44.661Z,1746469124.661 [NAL9602] Data Fault, FailCount= 1
2025-05-05T18:18:44.661Z,1746469124.661 [NAL9602](ERROR): Data Fault
2025-05-05T18:18:44.713Z,1746469124.713 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-05T18:18:45.064Z,1746469125.064 [NAL9602](INFO): Powering down
2025-05-05T18:18:45.890Z,1746469125.890 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-05T18:18:45.890Z,1746469125.890 [NAL9602] No Fault, FailCount= 1
2025-05-05T18:19:15.370Z,1746469155.370 [NAL9602](INFO): Powering up NAL9602
2025-05-05T18:19:26.275Z,1746469166.275 [NAL9602](INFO): NAL9602 initialized
2025-05-05T18:19:50.530Z,1746469190.530 [NAL9602](INFO): SBD MO Status=0, MOMSN=19320, MT Status=0, MTMSN=0
2025-05-05T18:19:50.530Z,1746469190.530 [NAL9602](INFO): No messages in MT queue
2025-05-05T18:21:57.839Z,1746469317.839 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182156.00,A,3647.87079,N,12151.01153,W,3.324,296.56,050525,,,A*7D
2025-05-05T18:21:57.841Z,1746469317.841 [NAL9602](INFO): GPS fix at 20250505T182156: (36.797846, -121.850192)
2025-05-05T18:21:57.859Z,1746469317.859 [Default:CheckIn:Read_GPS] Stopped
2025-05-05T18:21:57.860Z,1746469317.860 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-05T18:22:05.692Z,1746469325.692 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250505T155304/Courier0064.lzma
2025-05-05T18:22:06.693Z,1746469326.693 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Courier0064.lzma.bak
2025-05-05T18:22:06.693Z,1746469326.693 [DataOverHttps](INFO): SBD MOMSN=24773596
2025-05-05T18:22:22.599Z,1746469342.599 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20250505T155304/Express0065.lzma
2025-05-05T18:22:23.601Z,1746469343.601 [DataOverHttps](INFO): Moved sent file to Logs/20250505T155304/Express0065.lzma.bak
2025-05-05T18:22:23.601Z,1746469343.601 [DataOverHttps](INFO): SBD MOMSN=24773599
2025-05-05T18:22:24.652Z,1746469344.652 [Default:CheckIn:Read_Iridium] Stopped
2025-05-05T18:22:24.652Z,1746469344.652 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-05T18:22:24.652Z,1746469344.652 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-05T18:22:30.284Z,1746469350.284 [NAL9602](INFO): Powering down
2025-05-05T18:23:32.324Z,1746469412.324 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.259178
2025-05-05T18:23:42.788Z,1746469422.788 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003831
2025-05-05T18:24:41.019Z,1746469481.019 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-05-05T18:24:43.028Z,1746469483.028 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.243221
2025-05-05T18:24:53.473Z,1746469493.473 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003797
2025-05-05T18:25:45.112Z,1746469545.112 [DataOverHttps](IMPORTANT): SBD MTMSN=20250505T182544
2025-05-05T18:25:56.327Z,1746469556.327 [DataOverHttps](INFO): Received command: restart logs