2025-05-12T18:10:45.525Z,1747073445.525 [Supervisor](DEBUG): Initializing supervisor.
2025-05-12T18:10:45.530Z,1747073445.530 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-05-12T18:10:45.530Z,1747073445.530 [SyncHandler](INFO): Protected caller Thread ID is 1006
2025-05-12T18:10:45.531Z,1747073445.531 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-05-12T18:10:45.532Z,1747073445.532 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-05-12T18:10:45.532Z,1747073445.532 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1007
2025-05-12T18:10:45.537Z,1747073445.537 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-05-12T18:10:45.558Z,1747073445.558 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-05-12T18:10:45.559Z,1747073445.559 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-05-12T18:10:45.559Z,1747073445.559 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1008
2025-05-12T18:10:45.563Z,1747073445.563 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-05-12T18:10:45.564Z,1747073445.564 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-05-12T18:10:45.565Z,1747073445.565 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1009
2025-05-12T18:10:45.567Z,1747073445.567 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-05-12T18:10:45.568Z,1747073445.568 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-05-12T18:10:45.568Z,1747073445.568 [logger ThreadHandler](INFO): Protected caller Thread ID is 1010
2025-05-12T18:10:45.572Z,1747073445.572 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-05-12T18:10:45.573Z,1747073445.573 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-05-12T18:10:45.574Z,1747073445.574 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-05-12T18:10:45.680Z,1747073445.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-05-12T18:10:45.681Z,1747073445.681 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-05-12T18:10:45.917Z,1747073445.917 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-05-12T18:10:45.917Z,1747073445.917 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-05-12T18:10:46.193Z,1747073446.193 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-05-12T18:10:46.193Z,1747073446.193 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-05-12T18:10:46.311Z,1747073446.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-05-12T18:10:46.311Z,1747073446.311 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-05-12T18:10:47.091Z,1747073447.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-05-12T18:10:47.092Z,1747073447.092 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-05-12T18:10:47.623Z,1747073447.623 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-05-12T18:10:47.623Z,1747073447.623 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-05-12T18:10:48.193Z,1747073448.193 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-05-12T18:10:48.193Z,1747073448.193 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-05-12T18:10:48.859Z,1747073448.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-05-12T18:10:48.859Z,1747073448.859 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-05-12T18:10:49.238Z,1747073449.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-05-12T18:10:49.239Z,1747073449.239 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-05-12T18:10:49.634Z,1747073449.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-05-12T18:10:49.635Z,1747073449.635 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-05-12T18:10:49.873Z,1747073449.873 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-05-12T18:10:49.873Z,1747073449.873 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-05-12T18:10:50.025Z,1747073450.025 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-05-12T18:10:50.026Z,1747073450.026 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-05-12T18:10:50.118Z,1747073450.118 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-05-12T18:10:50.208Z,1747073450.208 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-05-12T18:10:50.411Z,1747073450.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-05-12T18:10:50.411Z,1747073450.411 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-05-12T18:10:50.674Z,1747073450.674 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-05-12T18:10:50.676Z,1747073450.676 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-05-12T18:10:50.677Z,1747073450.677 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-05-12T18:10:50.773Z,1747073450.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-05-12T18:10:51.053Z,1747073451.053 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-05-12T18:10:51.053Z,1747073451.053 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-05-12T18:10:51.147Z,1747073451.147 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-05-12T18:10:51.328Z,1747073451.328 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-05-12T18:10:51.438Z,1747073451.438 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-05-12T18:10:51.568Z,1747073451.568 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-05-12T18:10:51.691Z,1747073451.691 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-05-12T18:10:51.795Z,1747073451.795 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-05-12T18:10:51.967Z,1747073451.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-05-12T18:10:52.073Z,1747073452.073 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-05-12T18:10:52.167Z,1747073452.167 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-05-12T18:10:52.276Z,1747073452.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-05-12T18:10:52.524Z,1747073452.524 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2025-05-12T18:10:52.525Z,1747073452.525 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-05-12T18:10:52.658Z,1747073452.658 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-05-12T18:10:52.844Z,1747073452.844 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-05-12T18:10:52.845Z,1747073452.845 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-05-12T18:10:53.010Z,1747073453.010 [BuoyancyServo] Loaded
2025-05-12T18:10:53.011Z,1747073453.011 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-05-12T18:10:53.034Z,1747073453.034 [ElevatorServo] Loaded
2025-05-12T18:10:53.035Z,1747073453.035 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-05-12T18:10:53.057Z,1747073453.057 [MassServo] Loaded
2025-05-12T18:10:53.057Z,1747073453.057 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-05-12T18:10:53.079Z,1747073453.079 [RudderServo] Loaded
2025-05-12T18:10:53.080Z,1747073453.080 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-05-12T18:10:53.098Z,1747073453.098 [ThrusterHE] Loaded
2025-05-12T18:10:53.098Z,1747073453.098 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-05-12T18:10:53.098Z,1747073453.098 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-05-12T18:10:53.099Z,1747073453.099 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-05-12T18:10:53.268Z,1747073453.268 [SBIT](DEBUG): Construct Startup Built In Test.
2025-05-12T18:10:53.283Z,1747073453.283 [SBIT] Loaded
2025-05-12T18:10:53.284Z,1747073453.284 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-05-12T18:10:53.287Z,1747073453.287 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-05-12T18:10:53.308Z,1747073453.308 [IBIT] Loaded
2025-05-12T18:10:53.308Z,1747073453.308 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-05-12T18:10:53.313Z,1747073453.313 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-05-12T18:10:53.507Z,1747073453.507 [CBIT] Loaded
2025-05-12T18:10:53.507Z,1747073453.507 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-05-12T18:10:53.538Z,1747073453.538 [GFScanner] Loaded
2025-05-12T18:10:53.538Z,1747073453.538 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-05-12T18:10:53.539Z,1747073453.539 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-05-12T18:10:53.539Z,1747073453.539 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-05-12T18:10:53.707Z,1747073453.707 [CTD_Seabird] Loaded
2025-05-12T18:10:53.708Z,1747073453.708 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-05-12T18:10:53.709Z,1747073453.709 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406834E0
2025-05-12T18:10:53.709Z,1747073453.709 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1098
2025-05-12T18:10:53.744Z,1747073453.744 [ESPComponent] Loaded
2025-05-12T18:10:53.744Z,1747073453.744 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-05-12T18:10:53.766Z,1747073453.766 [PAR_Licor] Loaded
2025-05-12T18:10:53.767Z,1747073453.767 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-05-12T18:10:53.813Z,1747073453.813 [WetLabsBB2FL] Loaded
2025-05-12T18:10:53.813Z,1747073453.813 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-05-12T18:10:53.814Z,1747073453.814 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B34E0
2025-05-12T18:10:53.814Z,1747073453.814 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1099
2025-05-12T18:10:53.815Z,1747073453.815 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-05-12T18:10:53.815Z,1747073453.815 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-05-12T18:10:53.868Z,1747073453.868 [DepthRateCalculator] Loaded
2025-05-12T18:10:53.868Z,1747073453.868 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-05-12T18:10:53.873Z,1747073453.873 [PitchRateCalculator] Loaded
2025-05-12T18:10:53.874Z,1747073453.874 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-05-12T18:10:53.884Z,1747073453.884 [SpeedCalculator] Loaded
2025-05-12T18:10:53.884Z,1747073453.884 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-05-12T18:10:53.889Z,1747073453.889 [YawRateCalculator] Loaded
2025-05-12T18:10:53.889Z,1747073453.889 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-05-12T18:10:53.909Z,1747073453.909 [ElevatorOffsetCalculator] Loaded
2025-05-12T18:10:53.910Z,1747073453.910 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-05-12T18:10:53.910Z,1747073453.910 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-05-12T18:10:53.911Z,1747073453.911 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-05-12T18:10:54.255Z,1747073454.255 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-05-12T18:10:54.256Z,1747073454.256 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-05-12T18:10:54.286Z,1747073454.286 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-05-12T18:10:54.286Z,1747073454.286 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-05-12T18:10:54.532Z,1747073454.532 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-05-12T18:10:54.551Z,1747073454.551 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-05-12T18:10:54.565Z,1747073454.565 [NavChart] Loaded
2025-05-12T18:10:54.566Z,1747073454.566 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-05-12T18:10:54.595Z,1747073454.595 [UniversalFixResidualReporter] Loaded
2025-05-12T18:10:54.595Z,1747073454.595 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-05-12T18:10:54.595Z,1747073454.595 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-05-12T18:10:54.596Z,1747073454.596 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-05-12T18:10:55.270Z,1747073455.270 [AHRS_M2] Loaded
2025-05-12T18:10:55.270Z,1747073455.270 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-05-12T18:10:55.309Z,1747073455.309 [BackseatComponent] Loaded
2025-05-12T18:10:55.309Z,1747073455.309 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-05-12T18:10:55.310Z,1747073455.310 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0
2025-05-12T18:10:55.311Z,1747073455.311 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1100
2025-05-12T18:10:55.313Z,1747073455.313 [LcmUniversalReporter] Loaded
2025-05-12T18:10:55.314Z,1747073455.314 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-05-12T18:10:56.053Z,1747073456.053 [BPC1] Loaded
2025-05-12T18:10:56.053Z,1747073456.053 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-05-12T18:10:56.153Z,1747073456.153 [DAT] Loaded
2025-05-12T18:10:56.153Z,1747073456.153 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-05-12T18:10:56.154Z,1747073456.154 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0
2025-05-12T18:10:56.155Z,1747073456.155 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1101
2025-05-12T18:10:56.229Z,1747073456.229 [DataOverHttps] Loaded
2025-05-12T18:10:56.229Z,1747073456.229 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-05-12T18:10:56.230Z,1747073456.230 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0
2025-05-12T18:10:56.231Z,1747073456.231 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1102
2025-05-12T18:10:56.254Z,1747073456.254 [Depth_Keller] Loaded
2025-05-12T18:10:56.254Z,1747073456.254 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-05-12T18:10:56.259Z,1747073456.259 [DropWeight] Loaded
2025-05-12T18:10:56.260Z,1747073456.260 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-05-12T18:10:56.301Z,1747073456.301 [DVL_micro] Loaded
2025-05-12T18:10:56.301Z,1747073456.301 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2025-05-12T18:10:56.364Z,1747073456.364 [NAL9602] Loaded
2025-05-12T18:10:56.364Z,1747073456.364 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-05-12T18:10:56.390Z,1747073456.390 [Onboard] Loaded
2025-05-12T18:10:56.390Z,1747073456.390 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-05-12T18:10:56.391Z,1747073456.391 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0
2025-05-12T18:10:56.392Z,1747073456.392 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1103
2025-05-12T18:10:56.398Z,1747073456.398 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2025-05-12T18:10:56.412Z,1747073456.412 [PowerOnly] Loaded
2025-05-12T18:10:56.412Z,1747073456.412 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-05-12T18:10:56.426Z,1747073456.426 [Power24vConverter] Loaded
2025-05-12T18:10:56.426Z,1747073456.426 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-05-12T18:10:56.443Z,1747073456.443 [Radio_Surface] Loaded
2025-05-12T18:10:56.443Z,1747073456.443 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-05-12T18:10:56.444Z,1747073456.444 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B3F4E0
2025-05-12T18:10:56.444Z,1747073456.444 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1104
2025-05-12T18:10:56.460Z,1747073456.460 [Sonardyne_Nano] Loaded
2025-05-12T18:10:56.460Z,1747073456.460 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-05-12T18:10:56.461Z,1747073456.461 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-05-12T18:10:56.462Z,1747073456.462 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-05-12T18:10:56.523Z,1747073456.523 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-05-12T18:10:56.523Z,1747073456.523 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-05-12T18:10:56.579Z,1747073456.579 [VerticalControl](DEBUG): Construct VerticalControl.
2025-05-12T18:10:56.632Z,1747073456.632 [VerticalControl] Loaded
2025-05-12T18:10:56.633Z,1747073456.633 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-05-12T18:10:56.636Z,1747073456.636 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-05-12T18:10:56.680Z,1747073456.680 [HorizontalControl] Loaded
2025-05-12T18:10:56.681Z,1747073456.681 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-05-12T18:10:56.683Z,1747073456.683 [SpeedControl](DEBUG): Construct SpeedControl.
2025-05-12T18:10:56.685Z,1747073456.685 [SpeedControl] Loaded
2025-05-12T18:10:56.685Z,1747073456.685 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-05-12T18:10:56.688Z,1747073456.688 [LoopControl](DEBUG): Construct LoopControl.
2025-05-12T18:10:56.688Z,1747073456.688 [LoopControl] Loaded
2025-05-12T18:10:56.689Z,1747073456.689 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-05-12T18:10:56.689Z,1747073456.689 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-05-12T18:10:56.690Z,1747073456.690 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-05-12T18:10:56.700Z,1747073456.700 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-05-12T18:10:56.701Z,1747073456.701 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-05-12T18:10:57.062Z,1747073457.062 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-05-12T18:10:57.068Z,1747073457.068 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-05-12T18:10:57.071Z,1747073457.071 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-05-12T18:10:57.083Z,1747073457.083 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-05-12T18:10:57.084Z,1747073457.084 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0
2025-05-12T18:10:57.084Z,1747073457.084 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1105
2025-05-12T18:10:57.088Z,1747073457.088 [Supervisor](INFO): Main Thread ID is 823
2025-05-12T18:10:57.089Z,1747073457.089 [Supervisor](DEBUG): Running supervisor.
2025-05-12T18:10:57.089Z,1747073457.089 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1106
2025-05-12T18:10:57.090Z,1747073457.090 [CommandExec](INFO): Initializing the command executive.
2025-05-12T18:10:57.091Z,1747073457.091 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1107
2025-05-12T18:10:57.093Z,1747073457.093 [controlThread ThreadHandler](INFO): Handler Thread ID is 1108
2025-05-12T18:10:57.094Z,1747073457.094 [controlThread](DEBUG): Initializing ControlThread
2025-05-12T18:10:57.096Z,1747073457.096 [SBIT](INFO): Initialize SBIT Component.
2025-05-12T18:10:57.096Z,1747073457.096 [SBIT](IMPORTANT): git: 2025-05-12_B
2025-05-12T18:10:57.096Z,1747073457.096 [SBIT](INFO): git hash: 7c5b1c07405cfe7ca09821eb029d166d25d65d57
2025-05-12T18:10:57.097Z,1747073457.097 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-05-12T18:10:57.098Z,1747073457.098 [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-12T18:10:57.099Z,1747073457.099 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2025-05-12T18:10:57.100Z,1747073457.100 [IBIT](INFO): Initialize IBIT Component.
2025-05-12T18:10:57.101Z,1747073457.101 [CBIT](DEBUG): Initialize CBIT Component.
2025-05-12T18:10:57.102Z,1747073457.102 [logger ThreadHandler](INFO): Handler Thread ID is 1109
2025-05-12T18:10:57.112Z,1747073457.112 [CBIT](DEBUG): Initialized mux pins.
2025-05-12T18:10:57.113Z,1747073457.113 [CBIT](DEBUG): Initializing the watchdog timer.
2025-05-12T18:10:57.121Z,1747073457.121 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1110
2025-05-12T18:10:57.122Z,1747073457.122 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-05-12T18:10:57.126Z,1747073457.126 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1112
2025-05-12T18:10:57.129Z,1747073457.129 [WetLabsBB2FL](INFO): Powering up
2025-05-12T18:10:57.130Z,1747073457.130 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1114
2025-05-12T18:10:57.136Z,1747073457.136 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-05-12T18:10:57.137Z,1747073457.137 [CBIT](DEBUG): Initializing heartbeat.
2025-05-12T18:10:57.138Z,1747073457.138 [DAT ThreadHandler](INFO): Handler Thread ID is 1115
2025-05-12T18:10:57.139Z,1747073457.139 [DAT](INFO): Powering up
2025-05-12T18:10:57.139Z,1747073457.139 [DAT](DEBUG): Initializing DAT.
2025-05-12T18:10:57.142Z,1747073457.142 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1117
2025-05-12T18:10:57.143Z,1747073457.143 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-05-12T18:10:57.153Z,1747073457.153 [Onboard ThreadHandler](INFO): Handler Thread ID is 1118
2025-05-12T18:10:57.170Z,1747073457.170 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1119
2025-05-12T18:10:57.194Z,1747073457.194 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1120
2025-05-12T18:10:57.196Z,1747073457.196 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-05-12T18:10:57.196Z,1747073457.196 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-05-12T18:10:57.197Z,1747073457.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-05-12T18:10:57.197Z,1747073457.197 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-05-12T18:10:57.197Z,1747073457.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-05-12T18:10:57.197Z,1747073457.197 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-05-12T18:10:57.197Z,1747073457.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-05-12T18:10:57.198Z,1747073457.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-05-12T18:10:57.209Z,1747073457.209 [CBIT](DEBUG): Deactivating emergency mode.
2025-05-12T18:10:57.249Z,1747073457.249 [CBIT](DEBUG): Backplane powered.
2025-05-12T18:10:57.249Z,1747073457.249 [GFScanner](DEBUG): Initializing GFScanner
2025-05-12T18:10:57.249Z,1747073457.249 [GFScanner](DEBUG): Deactivating GF circuits.
2025-05-12T18:10:57.257Z,1747073457.257 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-05-12T18:10:57.257Z,1747073457.257 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-05-12T18:10:57.258Z,1747073457.258 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-05-12T18:10:57.258Z,1747073457.258 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-05-12T18:10:57.258Z,1747073457.258 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-05-12T18:10:57.260Z,1747073457.260 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-05-12T18:10:57.260Z,1747073457.260 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-05-12T18:10:57.264Z,1747073457.264 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-05-12T18:10:57.270Z,1747073457.270 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-05-12T18:10:57.270Z,1747073457.270 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-05-12T18:10:57.271Z,1747073457.271 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-05-12T18:10:57.272Z,1747073457.272 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-05-12T18:10:57.277Z,1747073457.277 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-05-12T18:10:57.277Z,1747073457.277 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-05-12T18:10:57.278Z,1747073457.278 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-05-12T18:10:57.437Z,1747073457.437 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="Startup">
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="StartupSatComms">
        <Sequence />
        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix />
        </ReadDatum>
        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications />
        </ReadDatum>
    </Aggregate>
</Mission>

2025-05-12T18:10:57.457Z,1747073457.457 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-12T18:10:57.530Z,1747073457.530 [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-12T18:10:57.531Z,1747073457.531 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-05-12T18:10:57.531Z,1747073457.531 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-05-12T18:10:57.532Z,1747073457.532 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-05-12T18:10:57.577Z,1747073457.577 [Radio_Surface](INFO): Powering up
2025-05-12T18:10:57.964Z,1747073457.964 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="Default">
    <DefineArg Name="ElapsedSinceDefaultStarted">
        <Units:minute />
        <Value>0</Value>
    </DefineArg>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Units:second />
            <Value>13</Value>
        </Setting>
    </Guidance:Wait>
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="CheckIn">
        <Sequence Repeat="288" />
        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M" />
            <Universal:time_fix />
        </ReadDatum>
        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence />
                    <Setting>
                        <Guidance:Execute.command />
                        <String>Burn on</String>
                    </Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications />
        </ReadDatum>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Units:minute />
                <Value>5</Value>
            </Setting>
        </Guidance:Wait>
        <Assign>
            <Sequence />
            <Arg Name="ElapsedSinceDefaultStarted" />
            <Elapsed>
                <Universal:mission_started />
            </Elapsed>
        </Assign>
        <Syslog Severity="Important">
            Default mission has been running for 
            <Arg Name="ElapsedSinceDefaultStarted" />
            <Units:minute />
        </Syslog>
    </Aggregate>
    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>
    <Guidance:Execute>
        <Sequence />
        <Setting>
            <Guidance:Execute.command />
            <String>restart logs</String>
        </Setting>
    </Guidance:Execute>
</Mission>

2025-05-12T18:10:57.986Z,1747073457.986 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-05-12T18:10:57.988Z,1747073457.988 [Default:A.Wait](DEBUG): Construct Wait.
2025-05-12T18:10:58.007Z,1747073458.007 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-12T18:10:58.073Z,1747073458.073 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-05-12T18:10:58.084Z,1747073458.084 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-05-12T18:10:58.106Z,1747073458.106 [Default:E.Execute](DEBUG): Construct Execute.
2025-05-12T18:10:58.109Z,1747073458.109 [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-12T18:10:58.126Z,1747073458.126 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-05-12T18:10:58.170Z,1747073458.170 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-05-12T18:10:58.229Z,1747073458.229 [Depth_Keller](INFO): Initializing.
2025-05-12T18:10:58.238Z,1747073458.238 [PowerOnly](INFO): Powering up loadControl
2025-05-12T18:10:58.257Z,1747073458.257 [Power24vConverter](INFO): Powering up.
2025-05-12T18:10:58.258Z,1747073458.258 [Sonardyne_Nano](INFO): Initializing.
2025-05-12T18:10:58.281Z,1747073458.281 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-05-12T18:10:58.307Z,1747073458.307 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-05-12T18:10:58.313Z,1747073458.313 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-05-12T18:10:58.314Z,1747073458.314 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-05-12T18:10:58.321Z,1747073458.321 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-05-12T18:10:58.322Z,1747073458.322 [MassServo](DEBUG): Initializing EZServoServo.
2025-05-12T18:10:58.329Z,1747073458.329 [MassServo](DEBUG): Initializing MassServo.
2025-05-12T18:10:58.330Z,1747073458.330 [RudderServo](DEBUG): Initializing EZServoServo.
2025-05-12T18:10:58.338Z,1747073458.338 [RudderServo](DEBUG): Initializing RudderServo.
2025-05-12T18:10:58.338Z,1747073458.338 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-05-12T18:10:58.345Z,1747073458.345 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-05-12T18:10:59.771Z,1747073459.771 [WetLabsBB2FL](INFO): Powering down
2025-05-12T18:11:00.564Z,1747073460.564 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-05-12T18:11:01.802Z,1747073461.802 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-05-12T18:11:09.241Z,1747073469.241 [DAT](INFO): DAT read: 

2025-05-12T18:11:09.243Z,1747073469.243 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2025-05-12T18:11:11.006Z,1747073471.006 [DAT](INFO): DAT read: MF Frequency Band

2025-05-12T18:11:11.007Z,1747073471.007 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2025-05-12T18:11:11.007Z,1747073471.007 [DAT](INFO): DAT read: May 12 2025 18:11:05 

2025-05-12T18:11:12.014Z,1747073472.014 [DAT](INFO): DAT read: Features enabled [Bearing]

2025-05-12T18:11:12.015Z,1747073472.015 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2025-05-12T18:11:12.015Z,1747073472.015 [DAT](INFO): commRate: 1200
2025-05-12T18:11:14.081Z,1747073474.081 [DAT](INFO): entering command mode
2025-05-12T18:11:14.281Z,1747073474.281 [DAT](INFO): DAT read: 

2025-05-12T18:11:14.282Z,1747073474.282 [DAT](INFO): DAT read: user:1>

2025-05-12T18:11:14.282Z,1747073474.282 [DAT](INFO): setting verbose to 3
2025-05-12T18:11:14.534Z,1747073474.534 [DAT](INFO): DAT read: user:1>

2025-05-12T18:11:14.535Z,1747073474.535 [DAT](INFO): DAT read: Verbose         | 3           

2025-05-12T18:11:14.535Z,1747073474.535 [DAT](INFO): set verbose to 3
2025-05-12T18:11:14.535Z,1747073474.535 [DAT](INFO): setting DatVerbose to 27440
2025-05-12T18:11:14.787Z,1747073474.787 [DAT](INFO): DAT read: user:2>

2025-05-12T18:11:14.788Z,1747073474.788 [DAT](INFO): DAT read: DatVerbose      | 27440       

2025-05-12T18:11:14.788Z,1747073474.788 [DAT](INFO): set DatVerbose to 27440
2025-05-12T18:11:14.789Z,1747073474.789 [DAT](INFO): setting transmit power to 8
2025-05-12T18:11:15.038Z,1747073475.038 [DAT](INFO): DAT read: user:3>

2025-05-12T18:11:15.039Z,1747073475.039 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2025-05-12T18:11:15.039Z,1747073475.039 [DAT](INFO): set transmit power to 8
2025-05-12T18:11:15.039Z,1747073475.039 [DAT](INFO): setting local address to 5
2025-05-12T18:11:15.289Z,1747073475.289 [DAT](INFO): DAT read: user:4>

2025-05-12T18:11:15.290Z,1747073475.290 [DAT](INFO): DAT read: LocalAddr       | 5           

2025-05-12T18:11:15.291Z,1747073475.291 [DAT](INFO): set local address to 5
2025-05-12T18:11:15.292Z,1747073475.292 [DAT](INFO): Setting time to: 18:11:15 And date to:5/12/2025
2025-05-12T18:11:15.541Z,1747073475.541 [DAT](INFO): DAT read: user:5>

2025-05-12T18:11:15.542Z,1747073475.542 [DAT](INFO): DAT read: Mon May 12, 2025  18:11:15  

2025-05-12T18:11:15.543Z,1747073475.543 [DAT](INFO): Local DAT time set to Mon May 12, 2025  18:11:15  

2025-05-12T18:11:26.463Z,1747073486.463 [NAL9602](INFO): Powering up NAL9602
2025-05-12T18:11:37.359Z,1747073497.359 [NAL9602](INFO): NAL9602 initialized
2025-05-12T18:11:56.792Z,1747073516.792 [SBIT](IMPORTANT): Beginning Startup BIT
2025-05-12T18:11:56.817Z,1747073516.817 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-12T18:12:01.426Z,1747073521.426 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.004444
CHAN A1 (24V): 0.003894
CHAN A2 (12V): -0.005405
CHAN A3 (5V): -0.004225
CHAN B0 (3.3V): -0.002141
CHAN B1 (3.15aV): -0.001862
CHAN B2 (3.15bV): -0.001302
CHAN B3 (GND): -0.000978
OPEN: 0.006880
Full Scale: +/- 1 mA
2025-05-12T18:12:50.581Z,1747073570.581 [SBIT](IMPORTANT): SBIT PASSED
2025-05-12T18:12:50.581Z,1747073570.581 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-05-12T18:12:50.582Z,1747073570.582 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;

2025-05-12T18:12:50.582Z,1747073570.582 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=1 bool;

2025-05-12T18:12:50.582Z,1747073570.582 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=5 minute;

2025-05-12T18:12:50.582Z,1747073570.582 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;

2025-05-12T18:12:50.582Z,1747073570.582 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;

2025-05-12T18:12:50.583Z,1747073570.583 [SBIT](IMPORTANT): ThrusterHE.bestEffortMode=0 bool;

2025-05-12T18:12:50.583Z,1747073570.583 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=210 cubic_centimeter;

2025-05-12T18:12:50.583Z,1747073570.583 [SBIT](IMPORTANT): VerticalControl.massDefault=10 millimeter;

2025-05-12T18:12:50.000Z,1747073571.000 [MissionManager](IMPORTANT): Started mission Startup
2025-05-12T18:12:51.000Z,1747073571.000 [Startup] Running Loop=1
2025-05-12T18:12:51.000Z,1747073571.000 [Startup](DEBUG): Aggregate::initialize Startup
2025-05-12T18:12:51.000Z,1747073571.000 [Startup:A.GoToSurface] Running Loop=1
2025-05-12T18:12:51.001Z,1747073571.001 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-12T18:12:51.001Z,1747073571.001 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-12T18:12:51.002Z,1747073571.002 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-12T18:12:51.002Z,1747073571.002 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-12T18:12:51.002Z,1747073571.002 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-12T18:12:51.003Z,1747073571.003 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-12T18:12:51.003Z,1747073571.003 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-12T18:12:51.005Z,1747073571.005 [Startup:StartupSatComms] Running Loop=1
2025-05-12T18:12:51.005Z,1747073571.005 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-05-12T18:12:51.005Z,1747073571.005 [Startup:StartupSatComms:A] Running Loop=1
2025-05-12T18:12:51.397Z,1747073571.397 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-05-12T18:12:59.084Z,1747073579.084 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-05-12T18:13:05.912Z,1747073585.912 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-05-12T18:13:09.195Z,1747073589.195 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005224
2025-05-12T18:13:21.318Z,1747073601.318 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-05-12T18:13:32.630Z,1747073612.630 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-05-12T18:13:51.181Z,1747073631.181 [Startup:StartupSatComms:A](INFO): Timed out from 2025-05-12T18:12:51.0Z
2025-05-12T18:13:51.181Z,1747073631.181 [Startup:StartupSatComms:A] Stopped
2025-05-12T18:13:51.181Z,1747073631.181 [Startup:StartupSatComms:B] Running Loop=1
2025-05-12T18:13:51.593Z,1747073631.593 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-12T18:13:57.624Z,1747073637.624 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-05-12T18:13:57.624Z,1747073637.624 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-12T18:13:57.658Z,1747073637.658 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-12T18:13:58.065Z,1747073638.065 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-12T18:13:58.065Z,1747073638.065 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-05-12T18:13:58.168Z,1747073638.168 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250512T180622/Courier0004.lzma
2025-05-12T18:13:59.173Z,1747073639.173 [DataOverHttps](INFO): Moved sent file to Logs/20250512T180622/Courier0004.lzma.bak
2025-05-12T18:13:59.173Z,1747073639.173 [DataOverHttps](INFO): SBD MOMSN=24854705
2025-05-12T18:14:15.068Z,1747073655.068 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250512T181045/Courier0000.lzma
2025-05-12T18:14:16.071Z,1747073656.071 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0000.lzma.bak
2025-05-12T18:14:16.071Z,1747073656.071 [DataOverHttps](INFO): SBD MOMSN=24854707
2025-05-12T18:14:31.946Z,1747073671.946 [DataOverHttps](INFO): Sending 919 bytes from file Logs/20250512T180622/Express0001.lzma
2025-05-12T18:14:32.946Z,1747073672.946 [DataOverHttps](INFO): Moved sent file to Logs/20250512T180622/Express0001.lzma.bak
2025-05-12T18:14:32.947Z,1747073672.947 [DataOverHttps](INFO): SBD MOMSN=24854710
2025-05-12T18:14:48.932Z,1747073688.932 [DataOverHttps](INFO): Sending 91 bytes from file Logs/20250512T180622/Express0005.lzma
2025-05-12T18:14:49.934Z,1747073689.934 [DataOverHttps](INFO): Moved sent file to Logs/20250512T180622/Express0005.lzma.bak
2025-05-12T18:14:49.935Z,1747073689.935 [DataOverHttps](INFO): SBD MOMSN=24854739
2025-05-12T18:14:51.402Z,1747073691.402 [Startup:StartupSatComms:B](INFO): Timed out from 2025-05-12T18:13:51.2Z
2025-05-12T18:14:51.402Z,1747073691.402 [Startup:StartupSatComms:B] Stopped
2025-05-12T18:14:51.403Z,1747073691.403 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-05-12T18:14:51.403Z,1747073691.403 [Startup:StartupSatComms] Stopped
2025-05-12T18:14:51.403Z,1747073691.403 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-05-12T18:14:51.404Z,1747073691.404 [Startup](INFO): Completed Startup
2025-05-12T18:14:51.404Z,1747073691.404 [MissionManager](INFO): Startup is completed.
2025-05-12T18:14:51.404Z,1747073691.404 [MissionManager](INFO): Uninitializing Mission Startup
2025-05-12T18:14:51.404Z,1747073691.404 [Startup] Stopped
2025-05-12T18:14:51.404Z,1747073691.404 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-05-12T18:14:51.405Z,1747073691.405 [Startup:A.GoToSurface] Stopped
2025-05-12T18:14:51.405Z,1747073691.405 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-05-12T18:14:51.840Z,1747073691.840 [MissionManager](IMPORTANT): Started mission Default
2025-05-12T18:14:51.840Z,1747073691.840 [Default] Running Loop=1
2025-05-12T18:14:51.840Z,1747073691.840 [Default](DEBUG): Aggregate::initialize Default
2025-05-12T18:14:51.857Z,1747073691.857 [Default:B.GoToSurface] Running Loop=1
2025-05-12T18:14:51.857Z,1747073691.857 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-12T18:14:51.858Z,1747073691.858 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-12T18:14:51.858Z,1747073691.858 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-12T18:14:51.858Z,1747073691.858 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-12T18:14:51.859Z,1747073691.859 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-12T18:14:51.859Z,1747073691.859 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-12T18:14:51.859Z,1747073691.859 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-12T18:14:51.859Z,1747073691.859 [Default:A.Wait] Running Loop=1
2025-05-12T18:14:51.859Z,1747073691.859 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:15:05.174Z,1747073705.174 [Default:A.Wait](INFO): Done Waiting.
2025-05-12T18:15:05.174Z,1747073705.174 [Default:A.Wait] Stopped
2025-05-12T18:15:05.174Z,1747073705.174 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T18:15:05.532Z,1747073705.532 [Default:CheckIn] Running Loop=1
2025-05-12T18:15:05.537Z,1747073705.537 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T18:15:05.537Z,1747073705.537 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T18:15:05.951Z,1747073705.951 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-05-12T18:15:27.846Z,1747073727.846 [DataOverHttps](INFO): Sending 863 bytes from file Logs/20250512T181045/Express0001.lzma
2025-05-12T18:15:28.846Z,1747073728.846 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0001.lzma.bak
2025-05-12T18:15:28.847Z,1747073728.847 [DataOverHttps](INFO): SBD MOMSN=24854742
2025-05-12T18:16:40.439Z,1747073800.439 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-12T18:16:58.647Z,1747073818.647 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-05-12T18:16:58.647Z,1747073818.647 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-12T18:16:58.675Z,1747073818.675 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-12T18:16:59.059Z,1747073819.059 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-12T18:16:59.059Z,1747073819.059 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-05-12T18:18:17.025Z,1747073897.025 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-12T18:18:17.026Z,1747073897.026 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-05-12T18:18:17.027Z,1747073897.027 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2025-05-12T18:18:17.030Z,1747073897.030 [BPC1](INFO): Received data from all battery sticks.
2025-05-12T18:19:59.701Z,1747073999.701 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-05-12T18:19:59.701Z,1747073999.701 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-12T18:19:59.732Z,1747073999.732 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-12T18:20:00.102Z,1747074000.102 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-12T18:20:00.102Z,1747074000.102 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-05-12T18:20:05.720Z,1747074005.720 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-12T18:15:05.5Z
2025-05-12T18:20:05.721Z,1747074005.721 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T18:20:05.721Z,1747074005.721 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T18:20:06.131Z,1747074006.131 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-12T18:20:13.061Z,1747074013.061 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250512T181045/Courier0004.lzma
2025-05-12T18:20:14.062Z,1747074014.062 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0004.lzma.bak
2025-05-12T18:20:14.063Z,1747074014.063 [DataOverHttps](INFO): SBD MOMSN=24854905
2025-05-12T18:20:31.897Z,1747074031.897 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20250512T181045/Express0005.lzma
2025-05-12T18:20:33.903Z,1747074033.903 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0005.lzma.bak
2025-05-12T18:20:33.903Z,1747074033.903 [DataOverHttps](INFO): SBD MOMSN=24854911
2025-05-12T18:20:35.230Z,1747074035.230 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T18:20:35.230Z,1747074035.230 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T18:20:35.231Z,1747074035.231 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:21:40.243Z,1747074100.243 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-12T18:21:40.244Z,1747074100.244 [NAL9602] Data Fault, FailCount= 1
2025-05-12T18:21:40.244Z,1747074100.244 [NAL9602](ERROR): Data Fault
2025-05-12T18:21:40.276Z,1747074100.276 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-12T18:21:40.643Z,1747074100.643 [NAL9602](INFO): Powering down
2025-05-12T18:21:41.475Z,1747074101.475 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-12T18:21:41.475Z,1747074101.475 [NAL9602] No Fault, FailCount= 1
2025-05-12T18:22:10.947Z,1747074130.947 [NAL9602](INFO): Powering up NAL9602
2025-05-12T18:22:21.844Z,1747074141.844 [NAL9602](INFO): NAL9602 initialized
2025-05-12T18:23:00.635Z,1747074180.635 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-05-12T18:23:00.635Z,1747074180.635 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-12T18:23:00.646Z,1747074180.646 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-12T18:23:01.055Z,1747074181.055 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-12T18:23:01.055Z,1747074181.055 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-05-12T18:25:35.805Z,1747074335.805 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T18:25:35.806Z,1747074335.806 [Default:CheckIn:C.Wait] Stopped
2025-05-12T18:25:35.806Z,1747074335.806 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T18:25:35.806Z,1747074335.806 [Default:CheckIn:D] Running Loop=1
2025-05-12T18:25:36.196Z,1747074336.196 [Default:CheckIn:D] Stopped
2025-05-12T18:25:36.196Z,1747074336.196 [Default:CheckIn:E] Running Loop=1
2025-05-12T18:25:36.602Z,1747074336.602 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  10.739259 min 
2025-05-12T18:25:36.602Z,1747074336.602 [Default:CheckIn:E] Stopped
2025-05-12T18:25:36.602Z,1747074336.602 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T18:25:36.602Z,1747074336.602 [Default:CheckIn] Stopped
2025-05-12T18:25:36.602Z,1747074336.602 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T18:25:36.603Z,1747074336.603 [Default:CheckIn](INFO): Running loop #2
2025-05-12T18:25:36.603Z,1747074336.603 [Default:CheckIn] Running Loop=2
2025-05-12T18:25:36.603Z,1747074336.603 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T18:25:36.603Z,1747074336.603 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T18:26:01.631Z,1747074361.631 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-05-12T18:26:01.631Z,1747074361.631 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-12T18:26:01.664Z,1747074361.664 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-12T18:26:02.038Z,1747074362.038 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-12T18:26:02.038Z,1747074362.038 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-05-12T18:28:01.619Z,1747074481.619 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182758.00,A,3648.17540,N,12147.27878,W,1.030,321.03,120525,,,A*70
2025-05-12T18:28:01.623Z,1747074481.623 [NAL9602](INFO): GPS fix at 20250512T182758: (36.802923, -121.787980)
2025-05-12T18:28:01.634Z,1747074481.634 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T18:28:01.634Z,1747074481.634 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T18:28:10.193Z,1747074490.193 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250512T181045/Courier0007.lzma
2025-05-12T18:28:11.194Z,1747074491.194 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0007.lzma.bak
2025-05-12T18:28:11.195Z,1747074491.195 [DataOverHttps](INFO): SBD MOMSN=24854993
2025-05-12T18:28:31.389Z,1747074511.389 [DataOverHttps](INFO): Sending 397 bytes from file Logs/20250512T181045/Express0008.lzma
2025-05-12T18:28:32.390Z,1747074512.390 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0008.lzma.bak
2025-05-12T18:28:32.390Z,1747074512.390 [DataOverHttps](INFO): SBD MOMSN=24855001
2025-05-12T18:28:33.567Z,1747074513.567 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T18:28:33.567Z,1747074513.567 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T18:28:33.567Z,1747074513.567 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:28:34.340Z,1747074514.340 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T18:31:44.558Z,1747074704.558 [DataOverHttps](IMPORTANT): SBD MTMSN=20250512T183143
2025-05-12T18:31:52.045Z,1747074712.045 [DataOverHttps](INFO): Received command: ibit
2025-05-12T18:31:52.098Z,1747074712.098 [CommandExec](IMPORTANT): got command ibit
2025-05-12T18:31:52.339Z,1747074712.339 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-05-12T18:31:52.339Z,1747074712.339 [IBIT](IMPORTANT): Beginning control surface checks.
2025-05-12T18:31:52.343Z,1747074712.343 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-12T18:31:53.921Z,1747074713.921 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183150.00,A,3648.13771,N,12147.23038,W,0.058,67.22,120525,,,A*4E
2025-05-12T18:31:53.924Z,1747074713.924 [NAL9602](INFO): GPS fix at 20250512T183150: (36.802295, -121.787173)
2025-05-12T18:31:56.948Z,1747074716.948 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006326
CHAN A1 (24V): 0.000363
CHAN A2 (12V): -0.005119
CHAN A3 (5V): -0.002430
CHAN B0 (3.3V): -0.000892
CHAN B1 (3.15aV): -0.001335
CHAN B2 (3.15bV): -0.001090
CHAN B3 (GND): 0.000377
OPEN: 0.006791
Full Scale: +/- 1 mA
2025-05-12T18:32:12.908Z,1747074732.908 [NAL9602](INFO): SBD MO Status=0, MOMSN=20595, MT Status=0, MTMSN=0
2025-05-12T18:32:12.908Z,1747074732.908 [NAL9602](INFO): No messages in MT queue
2025-05-12T18:32:14.119Z,1747074734.119 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183210.00,A,3648.13777,N,12147.23086,W,0.078,67.22,120525,,,A*48
2025-05-12T18:32:14.121Z,1747074734.121 [NAL9602](INFO): GPS fix at 20250512T183210: (36.802296, -121.787181)
2025-05-12T18:32:16.947Z,1747074736.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183213.00,A,3648.13807,N,12147.23087,W,0.739,67.22,120525,,,A*40
2025-05-12T18:32:16.949Z,1747074736.949 [NAL9602](INFO): GPS fix at 20250512T183213: (36.802301, -121.787181)
2025-05-12T18:32:19.783Z,1747074739.783 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183216.00,A,3648.13946,N,12147.23037,W,1.905,10.96,120525,,,A*45
2025-05-12T18:32:19.785Z,1747074739.785 [NAL9602](INFO): GPS fix at 20250512T183216: (36.802324, -121.787173)
2025-05-12T18:32:23.012Z,1747074743.012 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183219.00,A,3648.14105,N,12147.23017,W,1.924,7.73,120525,,,A*7E
2025-05-12T18:32:23.014Z,1747074743.014 [NAL9602](INFO): GPS fix at 20250512T183219: (36.802351, -121.787170)
2025-05-12T18:32:23.702Z,1747074743.702 [DataOverHttps](IMPORTANT): SBD MTMSN=20250512T183222
2025-05-12T18:32:25.837Z,1747074745.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183222.00,A,3648.14266,N,12147.22997,W,1.827,1.55,120525,,,A*70
2025-05-12T18:32:25.839Z,1747074745.839 [NAL9602](INFO): GPS fix at 20250512T183222: (36.802378, -121.787166)
2025-05-12T18:32:28.672Z,1747074748.672 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183225.00,A,3648.14416,N,12147.22982,W,1.808,6.57,120525,,,A*7A
2025-05-12T18:32:28.678Z,1747074748.678 [NAL9602](INFO): GPS fix at 20250512T183225: (36.802403, -121.787164)
2025-05-12T18:32:31.460Z,1747074751.460 [DataOverHttps](INFO): Received command: ibit
2025-05-12T18:32:31.525Z,1747074751.525 [CommandExec](IMPORTANT): got command ibit
2025-05-12T18:32:31.532Z,1747074751.532 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-05-12T18:32:31.532Z,1747074751.532 [IBIT](IMPORTANT): Beginning control surface checks.
2025-05-12T18:32:31.535Z,1747074751.535 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-12T18:32:31.892Z,1747074751.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183228.00,A,3648.14554,N,12147.22937,W,1.788,12.92,120525,,,A*45
2025-05-12T18:32:31.894Z,1747074751.894 [NAL9602](INFO): GPS fix at 20250512T183228: (36.802426, -121.787156)
2025-05-12T18:32:34.775Z,1747074754.775 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183231.00,A,3648.14702,N,12147.22892,W,1.633,12.81,120525,,,A*41
2025-05-12T18:32:34.777Z,1747074754.777 [NAL9602](INFO): GPS fix at 20250512T183231: (36.802450, -121.787149)
2025-05-12T18:32:36.081Z,1747074756.081 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007168
CHAN A1 (24V): 0.000395
CHAN A2 (12V): -0.005396
CHAN A3 (5V): -0.002145
CHAN B0 (3.3V): -0.001149
CHAN B1 (3.15aV): -0.000926
CHAN B2 (3.15bV): -0.001296
CHAN B3 (GND): 0.000389
OPEN: 0.006913
Full Scale: +/- 1 mA
2025-05-12T18:32:38.020Z,1747074758.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183234.00,A,3648.14834,N,12147.22840,W,1.730,18.96,120525,,,A*4F
2025-05-12T18:32:38.023Z,1747074758.023 [NAL9602](INFO): GPS fix at 20250512T183234: (36.802472, -121.787140)
2025-05-12T18:32:40.835Z,1747074760.835 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183237.00,A,3648.14974,N,12147.22784,W,1.672,20.77,120525,,,A*4D
2025-05-12T18:32:40.837Z,1747074760.837 [NAL9602](INFO): GPS fix at 20250512T183237: (36.802496, -121.787131)
2025-05-12T18:32:43.669Z,1747074763.669 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183240.00,A,3648.15110,N,12147.22730,W,1.458,18.81,120525,,,A*41
2025-05-12T18:32:43.671Z,1747074763.671 [NAL9602](INFO): GPS fix at 20250512T183240: (36.802518, -121.787122)
2025-05-12T18:32:46.903Z,1747074766.903 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183243.00,A,3648.15214,N,12147.22692,W,1.011,20.89,120525,,,A*46
2025-05-12T18:32:46.905Z,1747074766.905 [NAL9602](INFO): GPS fix at 20250512T183243: (36.802536, -121.787115)
2025-05-12T18:32:49.727Z,1747074769.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183246.00,A,3648.15325,N,12147.22619,W,1.361,39.71,120525,,,A*48
2025-05-12T18:32:49.729Z,1747074769.729 [NAL9602](INFO): GPS fix at 20250512T183246: (36.802554, -121.787103)
2025-05-12T18:32:52.959Z,1747074772.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183249.00,A,3648.15376,N,12147.22511,W,0.039,55.92,120525,,,A*42
2025-05-12T18:32:52.961Z,1747074772.961 [NAL9602](INFO): GPS fix at 20250512T183249: (36.802563, -121.787085)
2025-05-12T18:32:55.787Z,1747074775.787 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183252.00,A,3648.15413,N,12147.22560,W,0.039,55.92,120525,,,A*4A
2025-05-12T18:32:55.789Z,1747074775.789 [NAL9602](INFO): GPS fix at 20250512T183252: (36.802569, -121.787093)
2025-05-12T18:32:59.047Z,1747074779.047 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183255.00,A,3648.15430,N,12147.22578,W,0.019,55.92,120525,,,A*47
2025-05-12T18:32:59.055Z,1747074779.055 [NAL9602](INFO): GPS fix at 20250512T183255: (36.802572, -121.787096)
2025-05-12T18:33:01.854Z,1747074781.854 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183258.00,A,3648.15444,N,12147.22592,W,0.097,55.92,120525,,,A*4B
2025-05-12T18:33:01.856Z,1747074781.856 [NAL9602](INFO): GPS fix at 20250512T183258: (36.802574, -121.787099)
2025-05-12T18:33:04.688Z,1747074784.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183301.00,A,3648.15481,N,12147.22592,W,0.117,55.92,120525,,,A*46
2025-05-12T18:33:04.690Z,1747074784.690 [NAL9602](INFO): GPS fix at 20250512T183301: (36.802580, -121.787099)
2025-05-12T18:33:07.914Z,1747074787.914 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183304.00,A,3648.15505,N,12147.22596,W,0.175,55.92,120525,,,A*4E
2025-05-12T18:33:07.920Z,1747074787.920 [NAL9602](INFO): GPS fix at 20250512T183304: (36.802584, -121.787099)
2025-05-12T18:33:10.741Z,1747074790.741 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183307.00,A,3648.15514,N,12147.22602,W,0.389,55.92,120525,,,A*42
2025-05-12T18:33:10.743Z,1747074790.743 [NAL9602](INFO): GPS fix at 20250512T183307: (36.802586, -121.787100)
2025-05-12T18:33:13.971Z,1747074793.971 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183310.00,A,3648.15533,N,12147.22608,W,0.097,55.92,120525,,,A*47
2025-05-12T18:33:13.974Z,1747074793.974 [NAL9602](INFO): GPS fix at 20250512T183310: (36.802589, -121.787101)
2025-05-12T18:33:16.795Z,1747074796.795 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183313.00,A,3648.15537,N,12147.22614,W,0.058,55.92,120525,,,A*4E
2025-05-12T18:33:16.798Z,1747074796.798 [NAL9602](INFO): GPS fix at 20250512T183313: (36.802590, -121.787102)
2025-05-12T18:33:17.634Z,1747074797.634 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802589 Longitude: -121.787102
2025-05-12T18:33:18.039Z,1747074798.039 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.541000
2025-05-12T18:33:18.039Z,1747074798.039 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-05-12T18:33:18.039Z,1747074798.039 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-05-12T18:33:18.425Z,1747074798.425 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-05-12T18:33:18.426Z,1747074798.426 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-05-12T18:33:18.426Z,1747074798.426 [IBIT](IMPORTANT): Pressure:10.439825 PSI
2025-05-12T18:33:18.426Z,1747074798.426 [IBIT](IMPORTANT): Humidity:5.597607 %
2025-05-12T18:33:18.838Z,1747074798.838 [IBIT](IMPORTANT): Vehicle Pitch:-2.775337 degrees
2025-05-12T18:33:18.838Z,1747074798.838 [IBIT](IMPORTANT): Vehicle  Roll:2.898842 degrees
2025-05-12T18:33:18.838Z,1747074798.838 [IBIT](IMPORTANT): Vehicle  Heading:184.940704 degrees
2025-05-12T18:33:19.238Z,1747074799.238 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-05-12T18:33:19.238Z,1747074799.238 [IBIT](IMPORTANT): buoyancyNeutral: 210.000000 cc
2025-05-12T18:33:19.239Z,1747074799.239 [IBIT](IMPORTANT): massDefault: 1.000000 cm
2025-05-12T18:33:19.239Z,1747074799.239 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2025-05-12T18:33:19.239Z,1747074799.239 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-05-12T18:33:19.239Z,1747074799.239 [IBIT](IMPORTANT): IBIT PASSED
2025-05-12T18:33:34.213Z,1747074814.213 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T18:33:34.213Z,1747074814.213 [Default:CheckIn:C.Wait] Stopped
2025-05-12T18:33:34.213Z,1747074814.213 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T18:33:34.213Z,1747074814.213 [Default:CheckIn:D] Running Loop=1
2025-05-12T18:33:34.591Z,1747074814.591 [Default:CheckIn:D] Stopped
2025-05-12T18:33:34.591Z,1747074814.591 [Default:CheckIn:E] Running Loop=1
2025-05-12T18:33:34.990Z,1747074814.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  18.712508 min 
2025-05-12T18:33:34.990Z,1747074814.990 [Default:CheckIn:E] Stopped
2025-05-12T18:33:34.990Z,1747074814.990 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T18:33:34.990Z,1747074814.990 [Default:CheckIn] Stopped
2025-05-12T18:33:34.990Z,1747074814.990 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T18:33:34.991Z,1747074814.991 [Default:CheckIn](INFO): Running loop #3
2025-05-12T18:33:34.991Z,1747074814.991 [Default:CheckIn] Running Loop=3
2025-05-12T18:33:34.991Z,1747074814.991 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T18:33:34.991Z,1747074814.991 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T18:33:36.995Z,1747074816.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183333.00,A,3648.15514,N,12147.22628,W,0.136,55.92,120525,,,A*4B
2025-05-12T18:33:36.997Z,1747074816.997 [NAL9602](INFO): GPS fix at 20250512T183333: (36.802586, -121.787105)
2025-05-12T18:33:37.028Z,1747074817.028 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T18:33:37.028Z,1747074817.028 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T18:33:44.442Z,1747074824.442 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250512T181045/Courier0010.lzma
2025-05-12T18:33:45.442Z,1747074825.442 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0010.lzma.bak
2025-05-12T18:33:45.442Z,1747074825.442 [DataOverHttps](INFO): SBD MOMSN=24855031
2025-05-12T18:34:01.305Z,1747074841.305 [DataOverHttps](INFO): Sending 1287 bytes from file Logs/20250512T181045/Express0011.lzma
2025-05-12T18:34:02.302Z,1747074842.302 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0011.lzma.bak
2025-05-12T18:34:02.303Z,1747074842.303 [DataOverHttps](INFO): SBD MOMSN=24855034
2025-05-12T18:34:09.318Z,1747074849.318 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T18:34:18.305Z,1747074858.305 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20250512T181045/Express0014.lzma
2025-05-12T18:34:19.306Z,1747074859.306 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0014.lzma.bak
2025-05-12T18:34:19.307Z,1747074859.307 [DataOverHttps](INFO): SBD MOMSN=24855090
2025-05-12T18:34:20.635Z,1747074860.635 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T18:34:20.635Z,1747074860.635 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T18:34:20.635Z,1747074860.635 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:37:47.087Z,1747075067.087 [DVL_micro](ERROR): only read 3 of 4 data items for bottom velocity. Device response is::BI,-01474,-01482,+01366,9.99
2025-05-12T18:37:47.087Z,1747075067.087 [DVL_micro](ERROR): Failed to parse:
:BI,-01474,-01482,+01366,9.99
2025-05-12T18:39:21.217Z,1747075161.217 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T18:39:21.217Z,1747075161.217 [Default:CheckIn:C.Wait] Stopped
2025-05-12T18:39:21.217Z,1747075161.217 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T18:39:21.217Z,1747075161.217 [Default:CheckIn:D] Running Loop=1
2025-05-12T18:39:21.631Z,1747075161.631 [Default:CheckIn:D] Stopped
2025-05-12T18:39:21.631Z,1747075161.631 [Default:CheckIn:E] Running Loop=1
2025-05-12T18:39:22.024Z,1747075162.024 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  24.496507 min 
2025-05-12T18:39:22.040Z,1747075162.040 [Default:CheckIn:E] Stopped
2025-05-12T18:39:22.041Z,1747075162.041 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T18:39:22.041Z,1747075162.041 [Default:CheckIn] Stopped
2025-05-12T18:39:22.041Z,1747075162.041 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T18:39:22.041Z,1747075162.041 [Default:CheckIn](INFO): Running loop #4
2025-05-12T18:39:22.041Z,1747075162.041 [Default:CheckIn] Running Loop=4
2025-05-12T18:39:22.041Z,1747075162.041 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T18:39:22.041Z,1747075162.041 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T18:39:24.035Z,1747075164.035 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183923.00,A,3648.15303,N,12147.21799,W,0.039,131.83,120525,,,A*75
2025-05-12T18:39:24.037Z,1747075164.037 [NAL9602](INFO): GPS fix at 20250512T183923: (36.802551, -121.786967)
2025-05-12T18:39:24.047Z,1747075164.047 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T18:39:24.047Z,1747075164.047 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T18:39:31.985Z,1747075171.985 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250512T181045/Courier0016.lzma
2025-05-12T18:39:32.986Z,1747075172.986 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0016.lzma.bak
2025-05-12T18:39:32.987Z,1747075172.987 [DataOverHttps](INFO): SBD MOMSN=24855136
2025-05-12T18:39:40.605Z,1747075180.605 [NAL9602](INFO): SBD MO Status=0, MOMSN=20596, MT Status=0, MTMSN=0
2025-05-12T18:39:40.605Z,1747075180.605 [NAL9602](INFO): No messages in MT queue
2025-05-12T18:39:49.067Z,1747075189.067 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20250512T181045/Express0017.lzma
2025-05-12T18:39:50.062Z,1747075190.062 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0017.lzma.bak
2025-05-12T18:39:50.063Z,1747075190.063 [DataOverHttps](INFO): SBD MOMSN=24855139
2025-05-12T18:39:51.112Z,1747075191.112 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T18:39:51.112Z,1747075191.112 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T18:39:51.112Z,1747075191.112 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:40:11.307Z,1747075211.307 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T18:44:51.701Z,1747075491.701 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T18:44:51.701Z,1747075491.701 [Default:CheckIn:C.Wait] Stopped
2025-05-12T18:44:51.701Z,1747075491.701 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T18:44:51.701Z,1747075491.701 [Default:CheckIn:D] Running Loop=1
2025-05-12T18:44:52.112Z,1747075492.112 [Default:CheckIn:D] Stopped
2025-05-12T18:44:52.112Z,1747075492.112 [Default:CheckIn:E] Running Loop=1
2025-05-12T18:44:52.509Z,1747075492.509 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  30.004529 min 
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn:E] Stopped
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn] Stopped
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn](INFO): Running loop #5
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn] Running Loop=5
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T18:44:52.510Z,1747075492.510 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T18:44:54.515Z,1747075494.515 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184453.00,A,3648.15264,N,12147.21802,W,0.039,131.83,120525,,,D*70
2025-05-12T18:44:54.517Z,1747075494.517 [NAL9602](INFO): GPS fix at 20250512T184453: (36.802544, -121.786967)
2025-05-12T18:44:54.546Z,1747075494.546 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T18:44:54.546Z,1747075494.546 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T18:45:02.224Z,1747075502.224 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250512T181045/Courier0019.lzma
2025-05-12T18:45:03.226Z,1747075503.226 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0019.lzma.bak
2025-05-12T18:45:03.227Z,1747075503.227 [DataOverHttps](INFO): SBD MOMSN=24855162
2025-05-12T18:45:09.477Z,1747075509.477 [NAL9602](INFO): SBD MO Status=0, MOMSN=20597, MT Status=0, MTMSN=0
2025-05-12T18:45:09.478Z,1747075509.478 [NAL9602](INFO): No messages in MT queue
2025-05-12T18:45:19.205Z,1747075519.205 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20250512T181045/Express0020.lzma
2025-05-12T18:45:20.206Z,1747075520.206 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0020.lzma.bak
2025-05-12T18:45:20.207Z,1747075520.207 [DataOverHttps](INFO): SBD MOMSN=24855165
2025-05-12T18:45:21.593Z,1747075521.593 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T18:45:21.594Z,1747075521.594 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T18:45:21.594Z,1747075521.594 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:45:40.166Z,1747075540.166 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T18:50:22.196Z,1747075822.196 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T18:50:22.196Z,1747075822.196 [Default:CheckIn:C.Wait] Stopped
2025-05-12T18:50:22.196Z,1747075822.196 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T18:50:22.196Z,1747075822.196 [Default:CheckIn:D] Running Loop=1
2025-05-12T18:50:22.610Z,1747075822.610 [Default:CheckIn:D] Stopped
2025-05-12T18:50:22.610Z,1747075822.610 [Default:CheckIn:E] Running Loop=1
2025-05-12T18:50:23.004Z,1747075823.004 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  35.512834 min 
2025-05-12T18:50:23.004Z,1747075823.004 [Default:CheckIn:E] Stopped
2025-05-12T18:50:23.004Z,1747075823.004 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T18:50:23.004Z,1747075823.004 [Default:CheckIn] Stopped
2025-05-12T18:50:23.005Z,1747075823.005 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T18:50:23.005Z,1747075823.005 [Default:CheckIn](INFO): Running loop #6
2025-05-12T18:50:23.005Z,1747075823.005 [Default:CheckIn] Running Loop=6
2025-05-12T18:50:23.005Z,1747075823.005 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T18:50:23.005Z,1747075823.005 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T18:50:25.016Z,1747075825.016 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185024.00,A,3648.15213,N,12147.21870,W,0.078,131.83,120525,,,D*75
2025-05-12T18:50:25.019Z,1747075825.019 [NAL9602](INFO): GPS fix at 20250512T185024: (36.802535, -121.786978)
2025-05-12T18:50:25.029Z,1747075825.029 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T18:50:25.029Z,1747075825.029 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T18:50:32.300Z,1747075832.300 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250512T181045/Courier0022.lzma
2025-05-12T18:50:33.302Z,1747075833.302 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0022.lzma.bak
2025-05-12T18:50:33.303Z,1747075833.303 [DataOverHttps](INFO): SBD MOMSN=24855184
2025-05-12T18:50:49.353Z,1747075849.353 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20250512T181045/Express0023.lzma
2025-05-12T18:50:50.356Z,1747075850.356 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0023.lzma.bak
2025-05-12T18:50:50.356Z,1747075850.356 [DataOverHttps](INFO): SBD MOMSN=24855187
2025-05-12T18:50:51.689Z,1747075851.689 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T18:50:51.689Z,1747075851.689 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T18:50:51.689Z,1747075851.689 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:51:40.172Z,1747075900.172 [NAL9602](INFO): SBD MO Status=0, MOMSN=20598, MT Status=0, MTMSN=0
2025-05-12T18:51:40.173Z,1747075900.173 [NAL9602](INFO): No messages in MT queue
2025-05-12T18:52:10.867Z,1747075930.867 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T18:55:52.291Z,1747076152.291 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T18:55:52.291Z,1747076152.291 [Default:CheckIn:C.Wait] Stopped
2025-05-12T18:55:52.291Z,1747076152.291 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T18:55:52.291Z,1747076152.291 [Default:CheckIn:D] Running Loop=1
2025-05-12T18:55:52.704Z,1747076152.704 [Default:CheckIn:D] Stopped
2025-05-12T18:55:52.704Z,1747076152.704 [Default:CheckIn:E] Running Loop=1
2025-05-12T18:55:53.102Z,1747076153.102 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  41.014388 min 
2025-05-12T18:55:53.102Z,1747076153.102 [Default:CheckIn:E] Stopped
2025-05-12T18:55:53.102Z,1747076153.102 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T18:55:53.102Z,1747076153.102 [Default:CheckIn] Stopped
2025-05-12T18:55:53.102Z,1747076153.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T18:55:53.103Z,1747076153.103 [Default:CheckIn](INFO): Running loop #7
2025-05-12T18:55:53.103Z,1747076153.103 [Default:CheckIn] Running Loop=7
2025-05-12T18:55:53.103Z,1747076153.103 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T18:55:53.103Z,1747076153.103 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T18:55:55.107Z,1747076155.107 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185554.00,A,3648.15203,N,12147.21753,W,0.097,131.83,120525,,,D*79
2025-05-12T18:55:55.109Z,1747076155.109 [NAL9602](INFO): GPS fix at 20250512T185554: (36.802534, -121.786959)
2025-05-12T18:55:55.140Z,1747076155.140 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T18:55:55.140Z,1747076155.140 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T18:56:02.304Z,1747076162.304 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250512T181045/Courier0025.lzma
2025-05-12T18:56:03.306Z,1747076163.306 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0025.lzma.bak
2025-05-12T18:56:03.307Z,1747076163.307 [DataOverHttps](INFO): SBD MOMSN=24855237
2025-05-12T18:56:09.320Z,1747076169.320 [NAL9602](INFO): SBD MO Status=0, MOMSN=20599, MT Status=0, MTMSN=0
2025-05-12T18:56:09.321Z,1747076169.321 [NAL9602](INFO): No messages in MT queue
2025-05-12T18:56:19.376Z,1747076179.376 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250512T181045/Express0026.lzma
2025-05-12T18:56:20.378Z,1747076180.378 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0026.lzma.bak
2025-05-12T18:56:20.379Z,1747076180.379 [DataOverHttps](INFO): SBD MOMSN=24855240
2025-05-12T18:56:21.456Z,1747076181.456 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T18:56:21.456Z,1747076181.456 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T18:56:21.456Z,1747076181.456 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T18:56:40.026Z,1747076200.026 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T19:01:22.034Z,1747076482.034 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T19:01:22.034Z,1747076482.034 [Default:CheckIn:C.Wait] Stopped
2025-05-12T19:01:22.034Z,1747076482.034 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T19:01:22.034Z,1747076482.034 [Default:CheckIn:D] Running Loop=1
2025-05-12T19:01:22.448Z,1747076482.448 [Default:CheckIn:D] Stopped
2025-05-12T19:01:22.448Z,1747076482.448 [Default:CheckIn:E] Running Loop=1
2025-05-12T19:01:22.846Z,1747076482.846 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  46.510128 min 
2025-05-12T19:01:22.846Z,1747076482.846 [Default:CheckIn:E] Stopped
2025-05-12T19:01:22.846Z,1747076482.846 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T19:01:22.846Z,1747076482.846 [Default:CheckIn] Stopped
2025-05-12T19:01:22.846Z,1747076482.846 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T19:01:22.846Z,1747076482.846 [Default:CheckIn](INFO): Running loop #8
2025-05-12T19:01:22.847Z,1747076482.847 [Default:CheckIn] Running Loop=8
2025-05-12T19:01:22.847Z,1747076482.847 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T19:01:22.847Z,1747076482.847 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T19:01:24.852Z,1747076484.852 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190124.00,A,3648.31578,N,12147.12502,W,4.762,7.93,120525,,,D*79
2025-05-12T19:01:24.855Z,1747076484.855 [NAL9602](INFO): GPS fix at 20250512T190124: (36.805263, -121.785417)
2025-05-12T19:01:24.865Z,1747076484.865 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T19:01:24.865Z,1747076484.865 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T19:01:32.536Z,1747076492.536 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250512T181045/Courier0028.lzma
2025-05-12T19:01:33.538Z,1747076493.538 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0028.lzma.bak
2025-05-12T19:01:33.539Z,1747076493.539 [DataOverHttps](INFO): SBD MOMSN=24855254
2025-05-12T19:01:49.656Z,1747076509.656 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250512T181045/Express0029.lzma
2025-05-12T19:01:50.655Z,1747076510.655 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0029.lzma.bak
2025-05-12T19:01:50.655Z,1747076510.655 [DataOverHttps](INFO): SBD MOMSN=24855257
2025-05-12T19:01:51.928Z,1747076511.928 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T19:01:51.928Z,1747076511.928 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T19:01:51.928Z,1747076511.928 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T19:02:02.023Z,1747076522.023 [NAL9602](INFO): SBD MO Status=0, MOMSN=20600, MT Status=0, MTMSN=0
2025-05-12T19:02:02.023Z,1747076522.023 [NAL9602](INFO): No messages in MT queue
2025-05-12T19:02:32.719Z,1747076552.719 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T19:06:52.510Z,1747076812.510 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T19:06:52.510Z,1747076812.510 [Default:CheckIn:C.Wait] Stopped
2025-05-12T19:06:52.510Z,1747076812.510 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T19:06:52.511Z,1747076812.511 [Default:CheckIn:D] Running Loop=1
2025-05-12T19:06:52.917Z,1747076812.917 [Default:CheckIn:D] Stopped
2025-05-12T19:06:52.917Z,1747076812.917 [Default:CheckIn:E] Running Loop=1
2025-05-12T19:06:53.327Z,1747076813.327 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  52.017936 min 
2025-05-12T19:06:53.327Z,1747076813.327 [Default:CheckIn:E] Stopped
2025-05-12T19:06:53.328Z,1747076813.328 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T19:06:53.328Z,1747076813.328 [Default:CheckIn] Stopped
2025-05-12T19:06:53.328Z,1747076813.328 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T19:06:53.328Z,1747076813.328 [Default:CheckIn](INFO): Running loop #9
2025-05-12T19:06:53.328Z,1747076813.328 [Default:CheckIn] Running Loop=9
2025-05-12T19:06:53.328Z,1747076813.328 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T19:06:53.328Z,1747076813.328 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T19:06:55.335Z,1747076815.335 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190654.00,A,3648.38846,N,12147.42285,W,6.512,239.93,120525,,,A*70
2025-05-12T19:06:55.337Z,1747076815.337 [NAL9602](INFO): GPS fix at 20250512T190654: (36.806474, -121.790381)
2025-05-12T19:06:55.368Z,1747076815.368 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T19:06:55.368Z,1747076815.368 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T19:07:03.376Z,1747076823.376 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250512T181045/Courier0031.lzma
2025-05-12T19:07:04.379Z,1747076824.379 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0031.lzma.bak
2025-05-12T19:07:04.380Z,1747076824.380 [DataOverHttps](INFO): SBD MOMSN=24855287
2025-05-12T19:07:19.983Z,1747076839.983 [NAL9602](INFO): SBD MO Status=0, MOMSN=20601, MT Status=0, MTMSN=0
2025-05-12T19:07:19.983Z,1747076839.983 [NAL9602](INFO): No messages in MT queue
2025-05-12T19:07:20.395Z,1747076840.395 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250512T181045/Express0032.lzma
2025-05-12T19:07:21.395Z,1747076841.395 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0032.lzma.bak
2025-05-12T19:07:21.395Z,1747076841.395 [DataOverHttps](INFO): SBD MOMSN=24855290
2025-05-12T19:07:22.446Z,1747076842.446 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T19:07:22.447Z,1747076842.447 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T19:07:22.447Z,1747076842.447 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T19:07:50.676Z,1747076870.676 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T19:12:22.996Z,1747077142.996 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T19:12:22.996Z,1747077142.996 [Default:CheckIn:C.Wait] Stopped
2025-05-12T19:12:22.997Z,1747077142.997 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T19:12:22.997Z,1747077142.997 [Default:CheckIn:D] Running Loop=1
2025-05-12T19:12:23.406Z,1747077143.406 [Default:CheckIn:D] Stopped
2025-05-12T19:12:23.406Z,1747077143.406 [Default:CheckIn:E] Running Loop=1
2025-05-12T19:12:23.838Z,1747077143.838 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  57.526095 min 
2025-05-12T19:12:23.838Z,1747077143.838 [Default:CheckIn:E] Stopped
2025-05-12T19:12:23.838Z,1747077143.838 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T19:12:23.838Z,1747077143.838 [Default:CheckIn] Stopped
2025-05-12T19:12:23.839Z,1747077143.839 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T19:12:23.839Z,1747077143.839 [Default:CheckIn](INFO): Running loop #10
2025-05-12T19:12:23.839Z,1747077143.839 [Default:CheckIn] Running Loop=10
2025-05-12T19:12:23.839Z,1747077143.839 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T19:12:23.839Z,1747077143.839 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T19:12:25.816Z,1747077145.816 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191225.00,A,3648.23884,N,12148.28203,W,9.389,262.89,120525,,,D*71
2025-05-12T19:12:25.818Z,1747077145.818 [NAL9602](INFO): GPS fix at 20250512T191225: (36.803981, -121.804700)
2025-05-12T19:12:25.830Z,1747077145.830 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T19:12:25.830Z,1747077145.830 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T19:12:34.660Z,1747077154.660 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250512T181045/Courier0034.lzma
2025-05-12T19:12:35.662Z,1747077155.662 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0034.lzma.bak
2025-05-12T19:12:35.663Z,1747077155.663 [DataOverHttps](INFO): SBD MOMSN=24855303
2025-05-12T19:12:41.996Z,1747077161.996 [NAL9602](INFO): SBD MO Status=0, MOMSN=20602, MT Status=0, MTMSN=0
2025-05-12T19:12:41.996Z,1747077161.996 [NAL9602](INFO): No messages in MT queue
2025-05-12T19:12:52.052Z,1747077172.052 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20250512T181045/Express0035.lzma
2025-05-12T19:12:53.056Z,1747077173.056 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Express0035.lzma.bak
2025-05-12T19:12:53.056Z,1747077173.056 [DataOverHttps](INFO): SBD MOMSN=24855306
2025-05-12T19:12:54.108Z,1747077174.108 [Default:CheckIn:Read_Iridium] Stopped
2025-05-12T19:12:54.108Z,1747077174.108 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-12T19:12:54.108Z,1747077174.108 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-12T19:13:12.681Z,1747077192.681 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-12T19:17:54.781Z,1747077474.781 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-12T19:17:54.781Z,1747077474.781 [Default:CheckIn:C.Wait] Stopped
2025-05-12T19:17:54.781Z,1747077474.781 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-12T19:17:54.781Z,1747077474.781 [Default:CheckIn:D] Running Loop=1
2025-05-12T19:17:55.168Z,1747077475.168 [Default:CheckIn:D] Stopped
2025-05-12T19:17:55.168Z,1747077475.168 [Default:CheckIn:E] Running Loop=1
2025-05-12T19:17:55.574Z,1747077475.574 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  63.055469 min 
2025-05-12T19:17:55.574Z,1747077475.574 [Default:CheckIn:E] Stopped
2025-05-12T19:17:55.575Z,1747077475.575 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-12T19:17:55.575Z,1747077475.575 [Default:CheckIn] Stopped
2025-05-12T19:17:55.575Z,1747077475.575 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-12T19:17:55.575Z,1747077475.575 [Default:CheckIn](INFO): Running loop #11
2025-05-12T19:17:55.575Z,1747077475.575 [Default:CheckIn] Running Loop=11
2025-05-12T19:17:55.575Z,1747077475.575 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-12T19:17:55.575Z,1747077475.575 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-12T19:17:57.579Z,1747077477.579 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191757.00,A,3648.24192,N,12148.86489,W,0.117,220.04,120525,,,D*77
2025-05-12T19:17:57.591Z,1747077477.591 [NAL9602](INFO): GPS fix at 20250512T191757: (36.804032, -121.814415)
2025-05-12T19:17:57.602Z,1747077477.602 [Default:CheckIn:Read_GPS] Stopped
2025-05-12T19:17:57.603Z,1747077477.603 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-12T19:18:05.405Z,1747077485.405 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250512T181045/Courier0037.lzma
2025-05-12T19:18:06.408Z,1747077486.408 [DataOverHttps](INFO): Moved sent file to Logs/20250512T181045/Courier0037.lzma.bak
2025-05-12T19:18:06.408Z,1747077486.408 [DataOverHttps](INFO): SBD MOMSN=24855325
2025-05-12T19:18:14.994Z,1747077494.994 [DataOverHttps](IMPORTANT): SBD MTMSN=20250512T191814
2025-05-12T19:18:19.396Z,1747077499.396 [NAL9602](INFO): SBD MO Status=0, MOMSN=20603, MT Status=0, MTMSN=0
2025-05-12T19:18:19.396Z,1747077499.396 [NAL9602](INFO): No messages in MT queue
2025-05-12T19:18:22.577Z,1747077502.577 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250512T181045/Express0038.lzma
2025-05-12T19:18:22.579Z,1747077502.579 [DataOverHttps](INFO): Received command: restart logs