2025-04-08T15:22:04.091Z,1744125724.091 [Supervisor](DEBUG): Initializing supervisor. 2025-04-08T15:22:04.096Z,1744125724.096 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-04-08T15:22:04.096Z,1744125724.096 [SyncHandler](INFO): Protected caller Thread ID is 831 2025-04-08T15:22:04.097Z,1744125724.097 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-04-08T15:22:04.098Z,1744125724.098 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-04-08T15:22:04.098Z,1744125724.098 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 832 2025-04-08T15:22:04.102Z,1744125724.102 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-04-08T15:22:04.123Z,1744125724.123 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-04-08T15:22:04.124Z,1744125724.124 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-04-08T15:22:04.124Z,1744125724.124 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 833 2025-04-08T15:22:04.128Z,1744125724.128 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-04-08T15:22:04.129Z,1744125724.129 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-04-08T15:22:04.130Z,1744125724.130 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 834 2025-04-08T15:22:04.132Z,1744125724.132 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-04-08T15:22:04.133Z,1744125724.133 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-04-08T15:22:04.134Z,1744125724.134 [logger ThreadHandler](INFO): Protected caller Thread ID is 835 2025-04-08T15:22:04.137Z,1744125724.137 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-04-08T15:22:04.138Z,1744125724.138 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-04-08T15:22:04.143Z,1744125724.143 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-04-08T15:22:04.250Z,1744125724.250 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-04-08T15:22:04.252Z,1744125724.252 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-04-08T15:22:04.489Z,1744125724.489 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-04-08T15:22:04.491Z,1744125724.491 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-04-08T15:22:04.768Z,1744125724.768 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-04-08T15:22:04.770Z,1744125724.770 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-04-08T15:22:04.887Z,1744125724.887 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-04-08T15:22:04.889Z,1744125724.889 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-04-08T15:22:05.673Z,1744125725.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-04-08T15:22:05.673Z,1744125725.673 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-04-08T15:22:06.209Z,1744125726.209 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-04-08T15:22:06.209Z,1744125726.209 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-04-08T15:22:06.785Z,1744125726.785 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-04-08T15:22:06.785Z,1744125726.785 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-04-08T15:22:07.226Z,1744125727.226 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-04-08T15:22:07.393Z,1744125727.393 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-04-08T15:22:08.086Z,1744125728.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-04-08T15:22:08.087Z,1744125728.087 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-04-08T15:22:08.478Z,1744125728.478 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-04-08T15:22:08.478Z,1744125728.478 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-04-08T15:22:08.717Z,1744125728.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-04-08T15:22:08.719Z,1744125728.719 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-04-08T15:22:08.871Z,1744125728.871 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-04-08T15:22:08.872Z,1744125728.872 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-04-08T15:22:08.965Z,1744125728.965 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-04-08T15:22:09.055Z,1744125729.055 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-04-08T15:22:09.258Z,1744125729.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-04-08T15:22:09.260Z,1744125729.260 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-04-08T15:22:09.517Z,1744125729.517 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-04-08T15:22:09.519Z,1744125729.519 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2025-04-08T15:22:09.521Z,1744125729.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2025-04-08T15:22:09.616Z,1744125729.616 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2025-04-08T15:22:09.895Z,1744125729.895 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-04-08T15:22:09.896Z,1744125729.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2025-04-08T15:22:09.990Z,1744125729.990 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2025-04-08T15:22:10.214Z,1744125730.214 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2025-04-08T15:22:10.325Z,1744125730.325 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2025-04-08T15:22:10.445Z,1744125730.445 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2025-04-08T15:22:10.568Z,1744125730.568 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2025-04-08T15:22:10.673Z,1744125730.673 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2025-04-08T15:22:10.843Z,1744125730.843 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2025-04-08T15:22:10.950Z,1744125730.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg 2025-04-08T15:22:11.046Z,1744125731.046 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2025-04-08T15:22:11.154Z,1744125731.154 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2025-04-08T15:22:11.250Z,1744125731.250 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-04-08T15:22:11.274Z,1744125731.274 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-04-08T15:22:11.498Z,1744125731.498 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-04-08T15:22:11.498Z,1744125731.498 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-04-08T15:22:11.694Z,1744125731.694 [BuoyancyServo] Loaded 2025-04-08T15:22:11.695Z,1744125731.695 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-04-08T15:22:11.718Z,1744125731.718 [ElevatorServo] Loaded 2025-04-08T15:22:11.719Z,1744125731.719 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-04-08T15:22:11.742Z,1744125731.742 [MassServo] Loaded 2025-04-08T15:22:11.742Z,1744125731.742 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-04-08T15:22:11.765Z,1744125731.765 [RudderServo] Loaded 2025-04-08T15:22:11.765Z,1744125731.765 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-04-08T15:22:11.783Z,1744125731.783 [ThrusterHE] Loaded 2025-04-08T15:22:11.784Z,1744125731.784 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-04-08T15:22:11.784Z,1744125731.784 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-04-08T15:22:11.786Z,1744125731.786 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-04-08T15:22:11.987Z,1744125731.987 [SBIT](DEBUG): Construct Startup Built In Test. 2025-04-08T15:22:12.003Z,1744125732.003 [SBIT] Loaded 2025-04-08T15:22:12.003Z,1744125732.003 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-04-08T15:22:12.006Z,1744125732.006 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-04-08T15:22:12.027Z,1744125732.027 [IBIT] Loaded 2025-04-08T15:22:12.028Z,1744125732.028 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-04-08T15:22:12.033Z,1744125732.033 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-04-08T15:22:12.228Z,1744125732.228 [CBIT] Loaded 2025-04-08T15:22:12.228Z,1744125732.228 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-04-08T15:22:12.260Z,1744125732.260 [GFScanner] Loaded 2025-04-08T15:22:12.260Z,1744125732.260 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-04-08T15:22:12.261Z,1744125732.261 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-04-08T15:22:12.261Z,1744125732.261 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-04-08T15:22:13.196Z,1744125733.196 [CTD_Seabird] Loaded 2025-04-08T15:22:13.197Z,1744125733.197 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-04-08T15:22:13.198Z,1744125733.198 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406834E0 2025-04-08T15:22:13.198Z,1744125733.198 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 924 2025-04-08T15:22:13.234Z,1744125733.234 [ESPComponent] Loaded 2025-04-08T15:22:13.234Z,1744125733.234 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-04-08T15:22:13.256Z,1744125733.256 [PAR_Licor] Loaded 2025-04-08T15:22:13.256Z,1744125733.256 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-04-08T15:22:13.302Z,1744125733.302 [WetLabsBB2FL] Loaded 2025-04-08T15:22:13.303Z,1744125733.303 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-04-08T15:22:13.304Z,1744125733.304 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B34E0 2025-04-08T15:22:13.304Z,1744125733.304 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 925 2025-04-08T15:22:13.305Z,1744125733.305 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-04-08T15:22:13.307Z,1744125733.307 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-04-08T15:22:13.379Z,1744125733.379 [DepthRateCalculator] Loaded 2025-04-08T15:22:13.380Z,1744125733.380 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-04-08T15:22:13.385Z,1744125733.385 [PitchRateCalculator] Loaded 2025-04-08T15:22:13.385Z,1744125733.385 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-04-08T15:22:13.396Z,1744125733.396 [SpeedCalculator] Loaded 2025-04-08T15:22:13.396Z,1744125733.396 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-04-08T15:22:13.401Z,1744125733.401 [YawRateCalculator] Loaded 2025-04-08T15:22:13.401Z,1744125733.401 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-04-08T15:22:13.421Z,1744125733.421 [ElevatorOffsetCalculator] Loaded 2025-04-08T15:22:13.422Z,1744125733.422 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-04-08T15:22:13.422Z,1744125733.422 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-04-08T15:22:13.423Z,1744125733.423 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-04-08T15:22:13.593Z,1744125733.593 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-04-08T15:22:13.594Z,1744125733.594 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-04-08T15:22:13.642Z,1744125733.642 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-04-08T15:22:13.644Z,1744125733.644 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-04-08T15:22:13.786Z,1744125733.786 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-04-08T15:22:13.786Z,1744125733.786 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-04-08T15:22:13.801Z,1744125733.801 [NavChart] Loaded 2025-04-08T15:22:13.801Z,1744125733.801 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-04-08T15:22:13.807Z,1744125733.807 [UniversalFixResidualReporter] Loaded 2025-04-08T15:22:13.807Z,1744125733.807 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-04-08T15:22:13.807Z,1744125733.807 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-04-08T15:22:13.808Z,1744125733.808 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-04-08T15:22:14.701Z,1744125734.701 [AHRS_M2] Loaded 2025-04-08T15:22:14.701Z,1744125734.701 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-04-08T15:22:14.954Z,1744125734.954 [BackseatComponent] Loaded 2025-04-08T15:22:14.955Z,1744125734.955 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-04-08T15:22:14.956Z,1744125734.956 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0 2025-04-08T15:22:14.956Z,1744125734.956 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 926 2025-04-08T15:22:14.959Z,1744125734.959 [LcmUniversalReporter] Loaded 2025-04-08T15:22:14.959Z,1744125734.959 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-04-08T15:22:15.701Z,1744125735.701 [BPC1] Loaded 2025-04-08T15:22:15.701Z,1744125735.701 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-04-08T15:22:15.799Z,1744125735.799 [DAT] Loaded 2025-04-08T15:22:15.799Z,1744125735.799 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-04-08T15:22:15.800Z,1744125735.800 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0 2025-04-08T15:22:15.801Z,1744125735.801 [DAT ThreadHandler](INFO): Protected caller Thread ID is 927 2025-04-08T15:22:15.944Z,1744125735.944 [DataOverHttps] Loaded 2025-04-08T15:22:15.944Z,1744125735.944 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-04-08T15:22:15.945Z,1744125735.945 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0 2025-04-08T15:22:15.946Z,1744125735.946 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 928 2025-04-08T15:22:15.969Z,1744125735.969 [Depth_Keller] Loaded 2025-04-08T15:22:15.970Z,1744125735.970 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-04-08T15:22:15.975Z,1744125735.975 [DropWeight] Loaded 2025-04-08T15:22:15.975Z,1744125735.975 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-04-08T15:22:16.016Z,1744125736.016 [DVL_micro] Loaded 2025-04-08T15:22:16.016Z,1744125736.016 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2025-04-08T15:22:16.080Z,1744125736.080 [NAL9602] Loaded 2025-04-08T15:22:16.080Z,1744125736.080 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-04-08T15:22:16.107Z,1744125736.107 [Onboard] Loaded 2025-04-08T15:22:16.107Z,1744125736.107 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-04-08T15:22:16.108Z,1744125736.108 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0 2025-04-08T15:22:16.108Z,1744125736.108 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 929 2025-04-08T15:22:16.115Z,1744125736.115 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1 2025-04-08T15:22:16.129Z,1744125736.129 [PowerOnly] Loaded 2025-04-08T15:22:16.129Z,1744125736.129 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2025-04-08T15:22:16.143Z,1744125736.143 [Power24vConverter] Loaded 2025-04-08T15:22:16.143Z,1744125736.143 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-04-08T15:22:16.160Z,1744125736.160 [Radio_Surface] Loaded 2025-04-08T15:22:16.160Z,1744125736.160 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-04-08T15:22:16.161Z,1744125736.161 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B3F4E0 2025-04-08T15:22:16.162Z,1744125736.162 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 930 2025-04-08T15:22:16.178Z,1744125736.178 [Sonardyne_Nano] Loaded 2025-04-08T15:22:16.178Z,1744125736.178 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-04-08T15:22:16.179Z,1744125736.179 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-04-08T15:22:16.179Z,1744125736.179 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-04-08T15:22:16.664Z,1744125736.664 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-04-08T15:22:16.665Z,1744125736.665 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-04-08T15:22:17.176Z,1744125737.176 [VerticalControl](DEBUG): Construct VerticalControl. 2025-04-08T15:22:17.229Z,1744125737.229 [VerticalControl] Loaded 2025-04-08T15:22:17.230Z,1744125737.230 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-04-08T15:22:17.233Z,1744125737.233 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-04-08T15:22:17.278Z,1744125737.278 [HorizontalControl] Loaded 2025-04-08T15:22:17.278Z,1744125737.278 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-04-08T15:22:17.281Z,1744125737.281 [SpeedControl](DEBUG): Construct SpeedControl. 2025-04-08T15:22:17.283Z,1744125737.283 [SpeedControl] Loaded 2025-04-08T15:22:17.283Z,1744125737.283 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-04-08T15:22:17.286Z,1744125737.286 [LoopControl](DEBUG): Construct LoopControl. 2025-04-08T15:22:17.286Z,1744125737.286 [LoopControl] Loaded 2025-04-08T15:22:17.287Z,1744125737.287 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-04-08T15:22:17.287Z,1744125737.287 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-04-08T15:22:17.288Z,1744125737.288 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-04-08T15:22:17.304Z,1744125737.304 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-04-08T15:22:17.304Z,1744125737.304 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-04-08T15:22:17.728Z,1744125737.728 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-04-08T15:22:17.735Z,1744125737.735 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-04-08T15:22:17.738Z,1744125737.738 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-04-08T15:22:17.749Z,1744125737.749 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-04-08T15:22:17.750Z,1744125737.750 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0 2025-04-08T15:22:17.751Z,1744125737.751 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 931 2025-04-08T15:22:17.755Z,1744125737.755 [Supervisor](INFO): Main Thread ID is 824 2025-04-08T15:22:17.755Z,1744125737.755 [Supervisor](DEBUG): Running supervisor. 2025-04-08T15:22:17.756Z,1744125737.756 [CommandExec ThreadHandler](INFO): Handler Thread ID is 932 2025-04-08T15:22:17.756Z,1744125737.756 [CommandExec](INFO): Initializing the command executive. 2025-04-08T15:22:17.758Z,1744125737.758 [CommandLine ThreadHandler](INFO): Handler Thread ID is 933 2025-04-08T15:22:17.760Z,1744125737.760 [controlThread ThreadHandler](INFO): Handler Thread ID is 934 2025-04-08T15:22:17.760Z,1744125737.760 [controlThread](DEBUG): Initializing ControlThread 2025-04-08T15:22:17.762Z,1744125737.762 [SBIT](INFO): Initialize SBIT Component. 2025-04-08T15:22:17.763Z,1744125737.763 [SBIT](IMPORTANT): git: 2025-03-26-1-g1815535cc 2025-04-08T15:22:17.763Z,1744125737.763 [SBIT](INFO): git hash: 1815535cca105e464bdb7831f6233b5043f0283f 2025-04-08T15:22:17.763Z,1744125737.763 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-04-08T15:22:17.765Z,1744125737.765 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2025-04-08T15:22:17.766Z,1744125737.766 [SBIT](INFO): Beginning SBIT in 69.000000 seconds. 2025-04-08T15:22:17.766Z,1744125737.766 [IBIT](INFO): Initialize IBIT Component. 2025-04-08T15:22:17.767Z,1744125737.767 [CBIT](DEBUG): Initialize CBIT Component. 2025-04-08T15:22:17.768Z,1744125737.768 [logger ThreadHandler](INFO): Handler Thread ID is 935 2025-04-08T15:22:17.780Z,1744125737.780 [CBIT](DEBUG): Initialized mux pins. 2025-04-08T15:22:17.781Z,1744125737.781 [CBIT](DEBUG): Initializing the watchdog timer. 2025-04-08T15:22:17.793Z,1744125737.793 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 936 2025-04-08T15:22:17.794Z,1744125737.794 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-04-08T15:22:17.798Z,1744125737.798 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 938 2025-04-08T15:22:17.801Z,1744125737.801 [WetLabsBB2FL](INFO): Powering up 2025-04-08T15:22:17.802Z,1744125737.802 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 940 2025-04-08T15:22:17.805Z,1744125737.805 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-04-08T15:22:17.805Z,1744125737.805 [CBIT](DEBUG): Initializing heartbeat. 2025-04-08T15:22:17.820Z,1744125737.820 [DAT ThreadHandler](INFO): Handler Thread ID is 941 2025-04-08T15:22:17.820Z,1744125737.820 [DAT](INFO): Powering up 2025-04-08T15:22:17.821Z,1744125737.821 [DAT](DEBUG): Initializing DAT. 2025-04-08T15:22:17.826Z,1744125737.826 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 943 2025-04-08T15:22:17.827Z,1744125737.827 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-04-08T15:22:17.841Z,1744125737.841 [Onboard ThreadHandler](INFO): Handler Thread ID is 944 2025-04-08T15:22:17.858Z,1744125737.858 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 945 2025-04-08T15:22:17.876Z,1744125737.876 [CBIT](DEBUG): Deactivating emergency mode. 2025-04-08T15:22:17.889Z,1744125737.889 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 946 2025-04-08T15:22:17.897Z,1744125737.897 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-04-08T15:22:17.897Z,1744125737.897 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-04-08T15:22:17.897Z,1744125737.897 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-04-08T15:22:17.898Z,1744125737.898 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-04-08T15:22:17.898Z,1744125737.898 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-04-08T15:22:17.898Z,1744125737.898 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-04-08T15:22:17.898Z,1744125737.898 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-04-08T15:22:17.898Z,1744125737.898 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-04-08T15:22:17.917Z,1744125737.917 [CBIT](DEBUG): Backplane powered. 2025-04-08T15:22:17.917Z,1744125737.917 [GFScanner](DEBUG): Initializing GFScanner 2025-04-08T15:22:17.917Z,1744125737.917 [GFScanner](DEBUG): Deactivating GF circuits. 2025-04-08T15:22:17.925Z,1744125737.925 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-04-08T15:22:17.925Z,1744125737.925 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-04-08T15:22:17.926Z,1744125737.926 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-04-08T15:22:17.926Z,1744125737.926 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-04-08T15:22:17.926Z,1744125737.926 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-04-08T15:22:17.927Z,1744125737.927 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-04-08T15:22:17.928Z,1744125737.928 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-04-08T15:22:17.932Z,1744125737.932 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-04-08T15:22:17.941Z,1744125737.941 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-04-08T15:22:17.942Z,1744125737.942 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-04-08T15:22:17.943Z,1744125737.943 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-04-08T15:22:17.943Z,1744125737.943 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-04-08T15:22:17.944Z,1744125737.944 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-04-08T15:22:17.944Z,1744125737.944 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-04-08T15:22:17.956Z,1744125737.956 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-04-08T15:22:18.040Z,1744125738.040 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-04-08T15:22:18.053Z,1744125738.053 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-08T15:22:18.085Z,1744125738.085 [DAT](INFO): Using elevation to construct direction to contact in vehicle frame. 2025-04-08T15:22:18.099Z,1744125738.099 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2025-04-08T15:22:18.099Z,1744125738.099 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-04-08T15:22:18.099Z,1744125738.099 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-04-08T15:22:18.102Z,1744125738.102 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-04-08T15:22:18.265Z,1744125738.265 [Radio_Surface](INFO): Powering up 2025-04-08T15:22:18.414Z,1744125738.414 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2025-04-08T15:22:18.422Z,1744125738.422 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-04-08T15:22:18.423Z,1744125738.423 [Default:A.Wait](DEBUG): Construct Wait. 2025-04-08T15:22:18.438Z,1744125738.438 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-08T15:22:18.459Z,1744125738.459 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-04-08T15:22:18.482Z,1744125738.482 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-04-08T15:22:18.500Z,1744125738.500 [Default:E.Execute](DEBUG): Construct Execute. 2025-04-08T15:22:18.503Z,1744125738.503 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2025-04-08T15:22:18.517Z,1744125738.517 [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-04-08T15:22:18.531Z,1744125738.531 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-04-08T15:22:18.673Z,1744125738.673 [Depth_Keller](INFO): Initializing. 2025-04-08T15:22:18.677Z,1744125738.677 [Power24vConverter](INFO): Powering up. 2025-04-08T15:22:18.678Z,1744125738.678 [Sonardyne_Nano](INFO): Initializing. 2025-04-08T15:22:18.705Z,1744125738.705 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-04-08T15:22:18.749Z,1744125738.749 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-04-08T15:22:18.761Z,1744125738.761 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-04-08T15:22:18.762Z,1744125738.762 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-04-08T15:22:18.769Z,1744125738.769 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-04-08T15:22:18.770Z,1744125738.770 [MassServo](DEBUG): Initializing EZServoServo. 2025-04-08T15:22:18.777Z,1744125738.777 [MassServo](DEBUG): Initializing MassServo. 2025-04-08T15:22:18.778Z,1744125738.778 [RudderServo](DEBUG): Initializing EZServoServo. 2025-04-08T15:22:18.785Z,1744125738.785 [RudderServo](DEBUG): Initializing RudderServo. 2025-04-08T15:22:18.786Z,1744125738.786 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-04-08T15:22:18.793Z,1744125738.793 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-04-08T15:22:18.971Z,1744125738.971 [Depth_Keller](ERROR): Pressure or depth reading out of range: 947.322021 decibar, 0.000000 m 2025-04-08T15:22:18.972Z,1744125738.972 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-04-08T15:22:18.972Z,1744125738.972 [DropWeight] Hardware Fault, FailCount= 1 2025-04-08T15:22:18.972Z,1744125738.972 [DropWeight](ERROR): Hardware Fault 2025-04-08T15:22:18.979Z,1744125738.979 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-04-08T15:22:19.003Z,1744125739.003 [CommandExec](FAULT): Scheduling is paused 2025-04-08T15:22:19.004Z,1744125739.004 [CBIT](INFO): Critical error at 20250408T152218 2025-04-08T15:22:19.004Z,1744125739.004 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-04-08T15:22:19.014Z,1744125739.014 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-04-08T15:22:19.015Z,1744125739.015 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-04-08T15:22:19.353Z,1744125739.353 [CBIT](INFO): Critical error at 20250408T152219 2025-04-08T15:22:20.413Z,1744125740.413 [WetLabsBB2FL](INFO): Powering down 2025-04-08T15:22:20.955Z,1744125740.955 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-04-08T15:22:22.197Z,1744125742.197 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213 2025-04-08T15:22:24.421Z,1744125744.421 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-04-08T15:22:29.918Z,1744125749.918 [DAT](INFO): DAT read: 2025-04-08T15:22:29.919Z,1744125749.919 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-04-08T15:22:31.682Z,1744125751.682 [DAT](INFO): DAT read: MF Frequency Band 2025-04-08T15:22:31.683Z,1744125751.683 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-04-08T15:22:31.683Z,1744125751.683 [DAT](INFO): DAT read: Apr 8 2025 15:22:25 2025-04-08T15:22:32.942Z,1744125752.942 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-04-08T15:22:32.943Z,1744125752.943 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-04-08T15:22:32.943Z,1744125752.943 [DAT](INFO): commRate: 1200 2025-04-08T15:22:35.009Z,1744125755.009 [DAT](INFO): entering command mode 2025-04-08T15:22:35.209Z,1744125755.209 [DAT](INFO): DAT read: 2025-04-08T15:22:35.210Z,1744125755.210 [DAT](INFO): DAT read: user:1> 2025-04-08T15:22:35.210Z,1744125755.210 [DAT](INFO): setting verbose to 3 2025-04-08T15:22:35.464Z,1744125755.464 [DAT](INFO): DAT read: user:1> 2025-04-08T15:22:35.466Z,1744125755.466 [DAT](INFO): DAT read: Verbose | 3 2025-04-08T15:22:35.466Z,1744125755.466 [DAT](INFO): set verbose to 3 2025-04-08T15:22:35.467Z,1744125755.467 [DAT](INFO): setting DatVerbose to 27440 2025-04-08T15:22:35.713Z,1744125755.713 [DAT](INFO): DAT read: user:2> 2025-04-08T15:22:35.714Z,1744125755.714 [DAT](INFO): DAT read: DatVerbose | 27440 2025-04-08T15:22:35.715Z,1744125755.715 [DAT](INFO): set DatVerbose to 27440 2025-04-08T15:22:35.715Z,1744125755.715 [DAT](INFO): setting transmit power to 8 2025-04-08T15:22:35.965Z,1744125755.965 [DAT](INFO): DAT read: user:3> 2025-04-08T15:22:35.966Z,1744125755.966 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-04-08T15:22:35.967Z,1744125755.967 [DAT](INFO): set transmit power to 8 2025-04-08T15:22:35.967Z,1744125755.967 [DAT](INFO): setting local address to 5 2025-04-08T15:22:36.218Z,1744125756.218 [DAT](INFO): DAT read: user:4> 2025-04-08T15:22:36.219Z,1744125756.219 [DAT](INFO): DAT read: LocalAddr | 5 2025-04-08T15:22:36.219Z,1744125756.219 [DAT](INFO): set local address to 5 2025-04-08T15:22:36.220Z,1744125756.220 [DAT](INFO): Setting time to: 15:22:36 And date to:4/8/2025 2025-04-08T15:22:36.469Z,1744125756.469 [DAT](INFO): DAT read: user:5> 2025-04-08T15:22:36.470Z,1744125756.470 [DAT](INFO): DAT read: Tue Apr 8, 2025 15:22:36 2025-04-08T15:22:36.471Z,1744125756.471 [DAT](INFO): Local DAT time set to Tue Apr 8, 2025 15:22:36 2025-04-08T15:22:46.415Z,1744125766.415 [NAL9602](INFO): Powering up NAL9602 2025-04-08T15:22:57.330Z,1744125777.330 [NAL9602](INFO): NAL9602 initialized 2025-04-08T15:23:27.249Z,1744125807.249 [SBIT](IMPORTANT): Beginning Startup BIT 2025-04-08T15:23:27.254Z,1744125807.254 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T15:23:31.745Z,1744125811.745 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006664 CHAN A1 (24V): 0.000784 CHAN A2 (12V): -0.005778 CHAN A3 (5V): -0.002621 CHAN B0 (3.3V): -0.000937 CHAN B1 (3.15aV): -0.001565 CHAN B2 (3.15bV): -0.001197 CHAN B3 (GND): -0.000141 OPEN: 0.006707 Full Scale: +/- 1 mA 2025-04-08T15:23:53.108Z,1744125833.108 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T15:23:53.108Z,1744125833.108 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T15:24:08.772Z,1744125848.772 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005080 2025-04-08T15:24:21.423Z,1744125861.423 [SBIT](IMPORTANT): SBIT PASSED 2025-04-08T15:24:21.424Z,1744125861.424 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-04-08T15:24:21.437Z,1744125861.437 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=1 bool; 2025-04-08T15:24:21.437Z,1744125861.437 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count; 2025-04-08T15:24:21.437Z,1744125861.437 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool; 2025-04-08T15:24:21.437Z,1744125861.437 [SBIT](IMPORTANT): BuoyancyServo.loadAtStartup=1 bool; 2025-04-08T15:24:21.437Z,1744125861.437 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool; 2025-04-08T15:24:21.437Z,1744125861.437 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2025-04-08T15:24:21.437Z,1744125861.437 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): DropWeight.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): ElevatorServo.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): MassServo.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): NAL9602.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool; 2025-04-08T15:24:21.438Z,1744125861.438 [SBIT](IMPORTANT): Radio_Surface.loadAtStartup=1 bool; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): RudderServo.loadAtStartup=1 bool; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): ThrusterHE.loadAtStartup=1 bool; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=209.04 cubic_centimeter; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): VerticalControl.kdDepth=0.4 radian_per_second_per_meter; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): VerticalControl.kpDepth=0.1 radian_per_meter; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): VerticalControl.massDefault=12.4082 millimeter; 2025-04-08T15:24:21.439Z,1744125861.439 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=1 bool; 2025-04-08T15:24:21.834Z,1744125861.834 [MissionManager](IMPORTANT): Started mission Startup 2025-04-08T15:24:21.834Z,1744125861.834 [Startup] Running Loop=1 2025-04-08T15:24:21.834Z,1744125861.834 [Startup](DEBUG): Aggregate::initialize Startup 2025-04-08T15:24:21.834Z,1744125861.834 [Startup:A.GoToSurface] Running Loop=1 2025-04-08T15:24:21.835Z,1744125861.835 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-08T15:24:21.835Z,1744125861.835 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-08T15:24:21.836Z,1744125861.836 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-08T15:24:21.836Z,1744125861.836 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-08T15:24:21.836Z,1744125861.836 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-08T15:24:21.837Z,1744125861.837 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-08T15:24:21.837Z,1744125861.837 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-08T15:24:21.839Z,1744125861.839 [Startup:StartupSatComms] Running Loop=1 2025-04-08T15:24:21.839Z,1744125861.839 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-04-08T15:24:21.839Z,1744125861.839 [Startup:StartupSatComms:A] Running Loop=1 2025-04-08T15:24:22.233Z,1744125862.233 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-04-08T15:25:18.011Z,1744125918.011 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-04-08T15:25:18.011Z,1744125918.011 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-08T15:25:18.025Z,1744125918.025 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-08T15:25:18.413Z,1744125918.413 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-08T15:25:18.413Z,1744125918.413 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-04-08T15:25:22.070Z,1744125922.070 [Startup:StartupSatComms:A](INFO): Timed out from 2025-04-08T15:24:21.8Z 2025-04-08T15:25:22.070Z,1744125922.070 [Startup:StartupSatComms:A] Stopped 2025-04-08T15:25:22.070Z,1744125922.070 [Startup:StartupSatComms:B] Running Loop=1 2025-04-08T15:25:22.450Z,1744125922.450 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-08T15:25:29.500Z,1744125929.500 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250407T230812/Courier0280.lzma 2025-04-08T15:25:30.503Z,1744125930.503 [DataOverHttps](INFO): Moved sent file to Logs/20250407T230812/Courier0280.lzma.bak 2025-04-08T15:25:30.503Z,1744125930.503 [DataOverHttps](INFO): SBD MOMSN=24575244 2025-04-08T15:25:47.061Z,1744125947.061 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20250408T152204/Courier0000.lzma 2025-04-08T15:25:48.064Z,1744125948.064 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0000.lzma.bak 2025-04-08T15:25:48.064Z,1744125948.064 [DataOverHttps](INFO): SBD MOMSN=24575253 2025-04-08T15:26:04.024Z,1744125964.024 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250407T230812/Express0281.lzma 2025-04-08T15:26:05.027Z,1744125965.027 [DataOverHttps](INFO): Moved sent file to Logs/20250407T230812/Express0281.lzma.bak 2025-04-08T15:26:05.027Z,1744125965.027 [DataOverHttps](INFO): SBD MOMSN=24575282 2025-04-08T15:26:21.935Z,1744125981.935 [DataOverHttps](INFO): Sending 1055 bytes from file Logs/20250408T152204/Express0001.lzma 2025-04-08T15:26:22.242Z,1744125982.242 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-08T15:25:22.1Z 2025-04-08T15:26:22.242Z,1744125982.242 [Startup:StartupSatComms:B] Stopped 2025-04-08T15:26:22.242Z,1744125982.242 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-04-08T15:26:22.242Z,1744125982.242 [Startup:StartupSatComms] Stopped 2025-04-08T15:26:22.242Z,1744125982.242 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-04-08T15:26:22.243Z,1744125982.243 [Startup](INFO): Completed Startup 2025-04-08T15:26:22.243Z,1744125982.243 [MissionManager](INFO): Startup is completed. 2025-04-08T15:26:22.244Z,1744125982.244 [MissionManager](INFO): Uninitializing Mission Startup 2025-04-08T15:26:22.244Z,1744125982.244 [Startup] Stopped 2025-04-08T15:26:22.244Z,1744125982.244 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-04-08T15:26:22.244Z,1744125982.244 [Startup:A.GoToSurface] Stopped 2025-04-08T15:26:22.244Z,1744125982.244 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-08T15:26:22.650Z,1744125982.650 [MissionManager](IMPORTANT): Started mission Default 2025-04-08T15:26:22.650Z,1744125982.650 [Default] Running Loop=1 2025-04-08T15:26:22.650Z,1744125982.650 [Default](DEBUG): Aggregate::initialize Default 2025-04-08T15:26:22.650Z,1744125982.650 [Default:B.GoToSurface] Running Loop=1 2025-04-08T15:26:22.650Z,1744125982.650 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-08T15:26:22.650Z,1744125982.650 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-08T15:26:22.651Z,1744125982.651 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-08T15:26:22.651Z,1744125982.651 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-08T15:26:22.651Z,1744125982.651 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-08T15:26:22.652Z,1744125982.652 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-08T15:26:22.652Z,1744125982.652 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-08T15:26:22.652Z,1744125982.652 [Default:A.Wait] Running Loop=1 2025-04-08T15:26:22.652Z,1744125982.652 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-04-08T15:26:22.934Z,1744125982.934 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0001.lzma.bak 2025-04-08T15:26:22.934Z,1744125982.934 [DataOverHttps](INFO): SBD MOMSN=24575292 2025-04-08T15:26:35.991Z,1744125995.991 [Default:A.Wait](INFO): Done Waiting. 2025-04-08T15:26:35.991Z,1744125995.991 [Default:A.Wait] Stopped 2025-04-08T15:26:35.991Z,1744125995.991 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T15:26:36.406Z,1744125996.406 [Default:CheckIn] Running Loop=1 2025-04-08T15:26:36.406Z,1744125996.406 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T15:26:36.407Z,1744125996.407 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T15:26:36.784Z,1744125996.784 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-08T15:28:00.431Z,1744126080.431 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-08T15:28:19.017Z,1744126099.017 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-04-08T15:28:19.017Z,1744126099.017 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-08T15:28:19.028Z,1744126099.028 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-08T15:28:19.435Z,1744126099.435 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-08T15:28:19.435Z,1744126099.435 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-04-08T15:28:33.943Z,1744126113.943 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2025-04-08T15:28:33.946Z,1744126113.946 [BPC1](INFO): Received data from all battery sticks. 2025-04-08T15:28:56.654Z,1744126136.654 [CommandExec](IMPORTANT): got command strobe off 2025-04-08T15:28:56.654Z,1744126136.654 [CommandExec](IMPORTANT): Deactivating strobe 2025-04-08T15:31:20.009Z,1744126280.009 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-04-08T15:31:20.009Z,1744126280.009 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-08T15:31:20.020Z,1744126280.020 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-08T15:31:20.427Z,1744126280.427 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-08T15:31:20.428Z,1744126280.428 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-04-08T15:31:36.560Z,1744126296.560 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-04-08T15:26:36.4Z 2025-04-08T15:31:36.560Z,1744126296.560 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T15:31:36.560Z,1744126296.560 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T15:31:36.959Z,1744126296.959 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-08T15:31:43.399Z,1744126303.399 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250408T152204/Courier0004.lzma 2025-04-08T15:31:44.394Z,1744126304.394 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0004.lzma.bak 2025-04-08T15:31:44.394Z,1744126304.394 [DataOverHttps](INFO): SBD MOMSN=24575429 2025-04-08T15:32:03.061Z,1744126323.061 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20250408T152204/Express0005.lzma 2025-04-08T15:32:04.062Z,1744126324.062 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0005.lzma.bak 2025-04-08T15:32:04.063Z,1744126324.063 [DataOverHttps](INFO): SBD MOMSN=24575473 2025-04-08T15:32:05.687Z,1744126325.687 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T15:32:05.687Z,1744126325.687 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T15:32:05.687Z,1744126325.687 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T15:32:59.385Z,1744126379.385 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-04-08T15:32:59.385Z,1744126379.385 [NAL9602] Data Fault, FailCount= 1 2025-04-08T15:32:59.385Z,1744126379.385 [NAL9602](ERROR): Data Fault 2025-04-08T15:32:59.407Z,1744126379.407 [CBIT](ERROR): Data Fault in component: NAL9602 2025-04-08T15:32:59.783Z,1744126379.783 [NAL9602](INFO): Powering down 2025-04-08T15:33:00.622Z,1744126380.622 [CBIT](INFO): Clearing failed state for component NAL9602 2025-04-08T15:33:00.622Z,1744126380.622 [NAL9602] No Fault, FailCount= 1 2025-04-08T15:33:30.083Z,1744126410.083 [NAL9602](INFO): Powering up NAL9602 2025-04-08T15:33:40.995Z,1744126420.995 [NAL9602](INFO): NAL9602 initialized 2025-04-08T15:34:21.041Z,1744126461.041 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-04-08T15:34:21.041Z,1744126461.041 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-08T15:34:21.051Z,1744126461.051 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-08T15:34:21.410Z,1744126461.410 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-08T15:34:21.410Z,1744126461.410 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-04-08T15:37:06.231Z,1744126626.231 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T15:37:06.231Z,1744126626.231 [Default:CheckIn:C.Wait] Stopped 2025-04-08T15:37:06.231Z,1744126626.231 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T15:37:06.231Z,1744126626.231 [Default:CheckIn:D] Running Loop=1 2025-04-08T15:37:06.650Z,1744126626.650 [Default:CheckIn:D] Stopped 2025-04-08T15:37:06.650Z,1744126626.650 [Default:CheckIn:E] Running Loop=1 2025-04-08T15:37:07.051Z,1744126627.051 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.733337 min 2025-04-08T15:37:07.051Z,1744126627.051 [Default:CheckIn:E] Stopped 2025-04-08T15:37:07.051Z,1744126627.051 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T15:37:07.051Z,1744126627.051 [Default:CheckIn] Stopped 2025-04-08T15:37:07.052Z,1744126627.052 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T15:37:07.052Z,1744126627.052 [Default:CheckIn](INFO): Running loop #2 2025-04-08T15:37:07.052Z,1744126627.052 [Default:CheckIn] Running Loop=2 2025-04-08T15:37:07.052Z,1744126627.052 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T15:37:07.052Z,1744126627.052 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T15:37:19.164Z,1744126639.164 [CBIT](INFO): Clearing failed state for component DropWeight 2025-04-08T15:37:19.164Z,1744126639.164 [DropWeight] No Fault, FailCount= 1 2025-04-08T15:37:22.010Z,1744126642.010 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-04-08T15:37:22.010Z,1744126642.010 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-08T15:37:22.026Z,1744126642.026 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-08T15:37:22.450Z,1744126642.450 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-08T15:37:22.450Z,1744126642.450 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-04-08T15:40:23.012Z,1744126823.012 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-04-08T15:40:23.012Z,1744126823.012 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-04-08T15:40:23.055Z,1744126823.055 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-04-08T15:40:23.435Z,1744126823.435 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-04-08T15:40:23.435Z,1744126823.435 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-04-08T15:41:01.774Z,1744126861.774 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154034.00,A,3648.16435,N,12147.27739,W,0.136,137.01,080425,,,A*75 2025-04-08T15:41:01.778Z,1744126861.778 [NAL9602](INFO): GPS fix at 20250408T154034: (36.802739, -121.787957) 2025-04-08T15:41:01.809Z,1744126861.809 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T15:41:01.809Z,1744126861.809 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T15:41:09.805Z,1744126869.805 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250408T152204/Courier0007.lzma 2025-04-08T15:41:10.806Z,1744126870.806 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0007.lzma.bak 2025-04-08T15:41:10.807Z,1744126870.807 [DataOverHttps](INFO): SBD MOMSN=24575562 2025-04-08T15:41:29.053Z,1744126889.053 [DataOverHttps](INFO): Sending 413 bytes from file Logs/20250408T152204/Express0008.lzma 2025-04-08T15:41:30.055Z,1744126890.055 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0008.lzma.bak 2025-04-08T15:41:30.055Z,1744126890.055 [DataOverHttps](INFO): SBD MOMSN=24575566 2025-04-08T15:41:31.699Z,1744126891.699 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T15:41:31.699Z,1744126891.699 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T15:41:31.699Z,1744126891.699 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T15:41:34.498Z,1744126894.498 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-08T15:46:32.271Z,1744127192.271 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T15:46:32.271Z,1744127192.271 [Default:CheckIn:C.Wait] Stopped 2025-04-08T15:46:32.271Z,1744127192.271 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T15:46:32.271Z,1744127192.271 [Default:CheckIn:D] Running Loop=1 2025-04-08T15:46:32.656Z,1744127192.656 [Default:CheckIn:D] Stopped 2025-04-08T15:46:32.656Z,1744127192.656 [Default:CheckIn:E] Running Loop=1 2025-04-08T15:46:33.076Z,1744127193.076 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.166760 min 2025-04-08T15:46:33.076Z,1744127193.076 [Default:CheckIn:E] Stopped 2025-04-08T15:46:33.076Z,1744127193.076 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T15:46:33.076Z,1744127193.076 [Default:CheckIn] Stopped 2025-04-08T15:46:33.076Z,1744127193.076 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T15:46:33.077Z,1744127193.077 [Default:CheckIn](INFO): Running loop #3 2025-04-08T15:46:33.077Z,1744127193.077 [Default:CheckIn] Running Loop=3 2025-04-08T15:46:33.077Z,1744127193.077 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T15:46:33.077Z,1744127193.077 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T15:46:35.083Z,1744127195.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154610.00,A,3648.16696,N,12147.28457,W,0.408,229.34,080425,,,A*78 2025-04-08T15:46:35.085Z,1744127195.085 [NAL9602](INFO): GPS fix at 20250408T154610: (36.802783, -121.788076) 2025-04-08T15:46:35.097Z,1744127195.097 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T15:46:35.097Z,1744127195.097 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T15:46:42.731Z,1744127202.731 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T152204/Courier0010.lzma 2025-04-08T15:46:43.730Z,1744127203.730 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0010.lzma.bak 2025-04-08T15:46:43.731Z,1744127203.731 [DataOverHttps](INFO): SBD MOMSN=24575638 2025-04-08T15:47:03.001Z,1744127223.001 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250408T152204/Express0011.lzma 2025-04-08T15:47:04.002Z,1744127224.002 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0011.lzma.bak 2025-04-08T15:47:04.003Z,1744127224.003 [DataOverHttps](INFO): SBD MOMSN=24575641 2025-04-08T15:47:05.822Z,1744127225.822 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T15:47:05.822Z,1744127225.822 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T15:47:05.822Z,1744127225.822 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T15:48:45.975Z,1744127325.975 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2025-04-08T15:51:37.674Z,1744127497.674 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T15:51:37.674Z,1744127497.674 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T15:51:38.085Z,1744127498.085 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-08T15:52:06.364Z,1744127526.364 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T15:52:06.364Z,1744127526.364 [Default:CheckIn:C.Wait] Stopped 2025-04-08T15:52:06.364Z,1744127526.364 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T15:52:06.364Z,1744127526.364 [Default:CheckIn:D] Running Loop=1 2025-04-08T15:52:06.782Z,1744127526.782 [Default:CheckIn:D] Stopped 2025-04-08T15:52:06.782Z,1744127526.782 [Default:CheckIn:E] Running Loop=1 2025-04-08T15:52:07.172Z,1744127527.172 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.735535 min 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn:E] Stopped 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn] Stopped 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn](INFO): Running loop #4 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn] Running Loop=4 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T15:52:07.189Z,1744127527.189 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T15:52:09.180Z,1744127529.180 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155144.00,A,3648.16646,N,12147.28390,W,0.175,278.04,080425,,,D*73 2025-04-08T15:52:09.182Z,1744127529.182 [NAL9602](INFO): GPS fix at 20250408T155144: (36.802774, -121.788065) 2025-04-08T15:52:09.192Z,1744127529.192 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T15:52:09.192Z,1744127529.192 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T15:52:16.520Z,1744127536.520 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250408T152204/Courier0013.lzma 2025-04-08T15:52:17.522Z,1744127537.522 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0013.lzma.bak 2025-04-08T15:52:17.523Z,1744127537.523 [DataOverHttps](INFO): SBD MOMSN=24575665 2025-04-08T15:52:33.869Z,1744127553.869 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20250408T152204/Express0014.lzma 2025-04-08T15:52:34.870Z,1744127554.870 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0014.lzma.bak 2025-04-08T15:52:34.871Z,1744127554.871 [DataOverHttps](INFO): SBD MOMSN=24575669 2025-04-08T15:52:36.369Z,1744127556.369 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T15:52:36.369Z,1744127556.369 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T15:52:36.369Z,1744127556.369 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T15:52:41.629Z,1744127561.629 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-08T15:57:31.234Z,1744127851.234 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T15:57:31.561Z,1744127851.561 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T15:57:35.871Z,1744127855.871 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.372886 CHAN A1 (24V): 0.015433 CHAN A2 (12V): -0.015582 CHAN A3 (5V): -0.051127 CHAN B0 (3.3V): -0.008040 CHAN B1 (3.15aV): -0.010481 CHAN B2 (3.15bV): -0.001891 CHAN B3 (GND): -0.009014 OPEN: 0.012168 Full Scale: +/- 1 mA 2025-04-08T15:57:36.948Z,1744127856.948 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T15:57:36.948Z,1744127856.948 [Default:CheckIn:C.Wait] Stopped 2025-04-08T15:57:36.948Z,1744127856.948 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T15:57:36.949Z,1744127856.949 [Default:CheckIn:D] Running Loop=1 2025-04-08T15:57:37.349Z,1744127857.349 [Default:CheckIn:D] Stopped 2025-04-08T15:57:37.349Z,1744127857.349 [Default:CheckIn:E] Running Loop=1 2025-04-08T15:57:37.771Z,1744127857.771 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.244989 min 2025-04-08T15:57:37.771Z,1744127857.771 [Default:CheckIn:E] Stopped 2025-04-08T15:57:37.771Z,1744127857.771 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T15:57:37.771Z,1744127857.771 [Default:CheckIn] Stopped 2025-04-08T15:57:37.771Z,1744127857.771 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T15:57:37.771Z,1744127857.771 [Default:CheckIn](INFO): Running loop #5 2025-04-08T15:57:37.772Z,1744127857.772 [Default:CheckIn] Running Loop=5 2025-04-08T15:57:37.772Z,1744127857.772 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T15:57:37.772Z,1744127857.772 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T15:57:39.772Z,1744127859.772 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155715.00,A,3648.16928,N,12147.28200,W,0.175,324.39,080425,,,D*78 2025-04-08T15:57:39.775Z,1744127859.775 [NAL9602](INFO): GPS fix at 20250408T155715: (36.802821, -121.788033) 2025-04-08T15:57:39.791Z,1744127859.791 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T15:57:39.791Z,1744127859.791 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T15:57:47.060Z,1744127867.060 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250408T152204/Courier0016.lzma 2025-04-08T15:57:48.062Z,1744127868.062 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0016.lzma.bak 2025-04-08T15:57:48.063Z,1744127868.063 [DataOverHttps](INFO): SBD MOMSN=24575730 2025-04-08T15:58:04.349Z,1744127884.349 [DataOverHttps](INFO): Sending 359 bytes from file Logs/20250408T152204/Express0017.lzma 2025-04-08T15:58:05.350Z,1744127885.350 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0017.lzma.bak 2025-04-08T15:58:05.351Z,1744127885.351 [DataOverHttps](INFO): SBD MOMSN=24575733 2025-04-08T15:58:06.938Z,1744127886.938 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T15:58:06.938Z,1744127886.938 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T15:58:06.938Z,1744127886.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T15:59:05.225Z,1744127945.225 [CommandLine](INFO): End of History 2025-04-08T15:59:05.323Z,1744127945.323 [CommandLine](INFO): End of History 2025-04-08T15:59:05.325Z,1744127945.325 [CommandLine](INFO): End of History 2025-04-08T15:59:05.326Z,1744127945.326 [CommandLine](INFO): End of History 2025-04-08T15:59:05.378Z,1744127945.378 [CommandLine](INFO): End of History 2025-04-08T15:59:05.380Z,1744127945.380 [CommandLine](INFO): End of History 2025-04-08T15:59:05.381Z,1744127945.381 [CommandLine](INFO): End of History 2025-04-08T15:59:08.525Z,1744127948.525 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T15:59:08.720Z,1744127948.720 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T15:59:13.202Z,1744127953.202 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.011556 CHAN A1 (24V): 0.007798 CHAN A2 (12V): -0.027456 CHAN A3 (5V): -0.050566 CHAN B0 (3.3V): -0.009771 CHAN B1 (3.15aV): -0.003427 CHAN B2 (3.15bV): -0.002608 CHAN B3 (GND): -0.008376 OPEN: 0.012315 Full Scale: +/- 1 mA 2025-04-08T16:01:06.671Z,1744128066.671 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:01:06.672Z,1744128066.672 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:01:32.551Z,1744128092.551 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:01:32.551Z,1744128092.551 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:02:03.638Z,1744128123.638 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:02:03.639Z,1744128123.639 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:02:29.907Z,1744128149.907 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:02:29.907Z,1744128149.907 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:02:42.429Z,1744128162.429 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-08T16:03:07.636Z,1744128187.636 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T16:03:07.636Z,1744128187.636 [Default:CheckIn:C.Wait] Stopped 2025-04-08T16:03:07.636Z,1744128187.636 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T16:03:07.636Z,1744128187.636 [Default:CheckIn:D] Running Loop=1 2025-04-08T16:03:08.025Z,1744128188.025 [Default:CheckIn:D] Stopped 2025-04-08T16:03:08.025Z,1744128188.025 [Default:CheckIn:E] Running Loop=1 2025-04-08T16:03:08.440Z,1744128188.440 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.756254 min 2025-04-08T16:03:08.440Z,1744128188.440 [Default:CheckIn:E] Stopped 2025-04-08T16:03:08.441Z,1744128188.441 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T16:03:08.441Z,1744128188.441 [Default:CheckIn] Stopped 2025-04-08T16:03:08.441Z,1744128188.441 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T16:03:08.441Z,1744128188.441 [Default:CheckIn](INFO): Running loop #6 2025-04-08T16:03:08.441Z,1744128188.441 [Default:CheckIn] Running Loop=6 2025-04-08T16:03:08.441Z,1744128188.441 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T16:03:08.441Z,1744128188.441 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T16:03:10.443Z,1744128190.443 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160245.00,A,3648.16787,N,12147.28433,W,0.214,49.67,080425,,,D*44 2025-04-08T16:03:10.446Z,1744128190.446 [NAL9602](INFO): GPS fix at 20250408T160245: (36.802798, -121.788072) 2025-04-08T16:03:10.492Z,1744128190.492 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T16:03:10.492Z,1744128190.492 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T16:03:18.536Z,1744128198.536 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T152204/Courier0019.lzma 2025-04-08T16:03:19.538Z,1744128199.538 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0019.lzma.bak 2025-04-08T16:03:19.539Z,1744128199.539 [DataOverHttps](INFO): SBD MOMSN=24575757 2025-04-08T16:03:35.921Z,1744128215.921 [DataOverHttps](INFO): Sending 423 bytes from file Logs/20250408T152204/Express0020.lzma 2025-04-08T16:03:36.923Z,1744128216.923 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0020.lzma.bak 2025-04-08T16:03:36.923Z,1744128216.923 [DataOverHttps](INFO): SBD MOMSN=24575770 2025-04-08T16:03:38.736Z,1744128218.736 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T16:03:38.736Z,1744128218.736 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T16:03:38.736Z,1744128218.736 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T16:03:42.449Z,1744128222.449 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-08T16:07:20.541Z,1744128440.541 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-04-08T16:07:20.541Z,1744128440.541 [DropWeight] Hardware Fault, FailCount= 1 2025-04-08T16:07:20.541Z,1744128440.541 [DropWeight](ERROR): Hardware Fault 2025-04-08T16:07:20.609Z,1744128440.609 [CBIT](INFO): Critical error at 20250408T160720 2025-04-08T16:07:20.611Z,1744128440.611 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-04-08T16:07:20.611Z,1744128440.611 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-04-08T16:07:20.982Z,1744128440.982 [CBIT](INFO): Critical error at 20250408T160720 2025-04-08T16:08:39.345Z,1744128519.345 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T16:08:39.345Z,1744128519.345 [Default:CheckIn:C.Wait] Stopped 2025-04-08T16:08:39.345Z,1744128519.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T16:08:39.345Z,1744128519.345 [Default:CheckIn:D] Running Loop=1 2025-04-08T16:08:39.744Z,1744128519.744 [Default:CheckIn:D] Stopped 2025-04-08T16:08:39.744Z,1744128519.744 [Default:CheckIn:E] Running Loop=1 2025-04-08T16:08:40.164Z,1744128520.164 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.284904 min 2025-04-08T16:08:40.164Z,1744128520.164 [Default:CheckIn:E] Stopped 2025-04-08T16:08:40.164Z,1744128520.164 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T16:08:40.164Z,1744128520.164 [Default:CheckIn] Stopped 2025-04-08T16:08:40.164Z,1744128520.164 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T16:08:40.180Z,1744128520.180 [Default:CheckIn](INFO): Running loop #7 2025-04-08T16:08:40.181Z,1744128520.181 [Default:CheckIn] Running Loop=7 2025-04-08T16:08:40.181Z,1744128520.181 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T16:08:40.181Z,1744128520.181 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T16:08:42.158Z,1744128522.158 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160817.00,A,3648.16769,N,12147.28381,W,0.039,165.71,080425,,,D*72 2025-04-08T16:08:42.160Z,1744128522.160 [NAL9602](INFO): GPS fix at 20250408T160817: (36.802795, -121.788064) 2025-04-08T16:08:42.171Z,1744128522.171 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T16:08:42.171Z,1744128522.171 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T16:08:49.876Z,1744128529.876 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250408T152204/Courier0022.lzma 2025-04-08T16:08:50.878Z,1744128530.878 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0022.lzma.bak 2025-04-08T16:08:50.879Z,1744128530.879 [DataOverHttps](INFO): SBD MOMSN=24575828 2025-04-08T16:09:09.377Z,1744128549.377 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250408T152204/Express0023.lzma 2025-04-08T16:09:10.379Z,1744128550.379 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0023.lzma.bak 2025-04-08T16:09:10.379Z,1744128550.379 [DataOverHttps](INFO): SBD MOMSN=24575833 2025-04-08T16:09:12.073Z,1744128552.073 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T16:09:12.073Z,1744128552.073 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T16:09:12.073Z,1744128552.073 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T16:09:12.862Z,1744128552.862 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-04-08T16:09:12.945Z,1744128552.945 [NAL9602](ERROR): received: +CSQ:0 OK211, 2, 0, 0, 0 OK 2025-04-08T16:09:33.476Z,1744128573.476 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:09:33.476Z,1744128573.476 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:10:49.827Z,1744128649.827 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:10:49.827Z,1744128649.827 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:11:25.949Z,1744128685.949 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:11:26.194Z,1744128686.194 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:11:30.654Z,1744128690.654 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.002880 CHAN A1 (24V): 0.011541 CHAN A2 (12V): -0.020913 CHAN A3 (5V): -0.034849 CHAN B0 (3.3V): -0.007955 CHAN B1 (3.15aV): -0.003636 CHAN B2 (3.15bV): -0.001693 CHAN B3 (GND): -0.005745 OPEN: 0.012075 Full Scale: +/- 1 mA 2025-04-08T16:12:07.790Z,1744128727.790 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:12:07.790Z,1744128727.790 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:12:30.415Z,1744128750.415 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:12:30.415Z,1744128750.415 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:13:44.353Z,1744128824.353 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-08T16:14:12.653Z,1744128852.653 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T16:14:12.653Z,1744128852.653 [Default:CheckIn:C.Wait] Stopped 2025-04-08T16:14:12.653Z,1744128852.653 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T16:14:12.653Z,1744128852.653 [Default:CheckIn:D] Running Loop=1 2025-04-08T16:14:13.045Z,1744128853.045 [Default:CheckIn:D] Stopped 2025-04-08T16:14:13.045Z,1744128853.045 [Default:CheckIn:E] Running Loop=1 2025-04-08T16:14:13.468Z,1744128853.468 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.839921 min 2025-04-08T16:14:13.468Z,1744128853.468 [Default:CheckIn:E] Stopped 2025-04-08T16:14:13.468Z,1744128853.468 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T16:14:13.468Z,1744128853.468 [Default:CheckIn] Stopped 2025-04-08T16:14:13.468Z,1744128853.468 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T16:14:13.469Z,1744128853.469 [Default:CheckIn](INFO): Running loop #8 2025-04-08T16:14:13.469Z,1744128853.469 [Default:CheckIn] Running Loop=8 2025-04-08T16:14:13.469Z,1744128853.469 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T16:14:13.469Z,1744128853.469 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T16:14:15.471Z,1744128855.471 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161350.00,A,3648.16340,N,12147.27665,W,0.039,170.97,080425,,,D*78 2025-04-08T16:14:15.473Z,1744128855.473 [NAL9602](INFO): GPS fix at 20250408T161350: (36.802723, -121.787944) 2025-04-08T16:14:15.508Z,1744128855.508 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T16:14:15.508Z,1744128855.508 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T16:14:23.139Z,1744128863.139 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250408T152204/Courier0025.lzma 2025-04-08T16:14:24.141Z,1744128864.141 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0025.lzma.bak 2025-04-08T16:14:24.141Z,1744128864.141 [DataOverHttps](INFO): SBD MOMSN=24575865 2025-04-08T16:14:27.585Z,1744128867.585 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:14:27.693Z,1744128867.693 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:14:32.108Z,1744128872.108 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.005170 CHAN A1 (24V): 0.010503 CHAN A2 (12V): -0.019698 CHAN A3 (5V): -0.051531 CHAN B0 (3.3V): -0.007778 CHAN B1 (3.15aV): -0.004489 CHAN B2 (3.15bV): -0.002211 CHAN B3 (GND): -0.006516 OPEN: 0.012086 Full Scale: +/- 1 mA 2025-04-08T16:14:40.849Z,1744128880.849 [DataOverHttps](INFO): Sending 454 bytes from file Logs/20250408T152204/Express0026.lzma 2025-04-08T16:14:41.553Z,1744128881.553 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:14:41.769Z,1744128881.769 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:14:41.851Z,1744128881.851 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0026.lzma.bak 2025-04-08T16:14:41.851Z,1744128881.851 [DataOverHttps](INFO): SBD MOMSN=24575870 2025-04-08T16:14:43.767Z,1744128883.767 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T16:14:43.767Z,1744128883.767 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T16:14:43.767Z,1744128883.767 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T16:14:46.285Z,1744128886.285 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.007592 CHAN A1 (24V): 0.006062 CHAN A2 (12V): -0.028518 CHAN A3 (5V): -0.040928 CHAN B0 (3.3V): -0.008530 CHAN B1 (3.15aV): -0.002900 CHAN B2 (3.15bV): -0.001974 CHAN B3 (GND): -0.010813 OPEN: 0.011950 Full Scale: +/- 1 mA 2025-04-08T16:14:47.400Z,1744128887.400 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-08T16:17:56.189Z,1744129076.189 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:17:56.559Z,1744129076.559 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:18:00.938Z,1744129080.938 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.004260 CHAN A1 (24V): 0.015371 CHAN A2 (12V): -0.017649 CHAN A3 (5V): -0.031082 CHAN B0 (3.3V): -0.011045 CHAN B1 (3.15aV): -0.003795 CHAN B2 (3.15bV): -0.001933 CHAN B3 (GND): -0.004756 OPEN: 0.012154 Full Scale: +/- 1 mA 2025-04-08T16:19:44.358Z,1744129184.358 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T16:19:44.358Z,1744129184.358 [Default:CheckIn:C.Wait] Stopped 2025-04-08T16:19:44.358Z,1744129184.358 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T16:19:44.358Z,1744129184.358 [Default:CheckIn:D] Running Loop=1 2025-04-08T16:19:44.778Z,1744129184.778 [Default:CheckIn:D] Stopped 2025-04-08T16:19:44.779Z,1744129184.779 [Default:CheckIn:E] Running Loop=1 2025-04-08T16:19:45.162Z,1744129185.162 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.368807 min 2025-04-08T16:19:45.162Z,1744129185.162 [Default:CheckIn:E] Stopped 2025-04-08T16:19:45.163Z,1744129185.163 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T16:19:45.163Z,1744129185.163 [Default:CheckIn] Stopped 2025-04-08T16:19:45.163Z,1744129185.163 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T16:19:45.163Z,1744129185.163 [Default:CheckIn](INFO): Running loop #9 2025-04-08T16:19:45.163Z,1744129185.163 [Default:CheckIn] Running Loop=9 2025-04-08T16:19:45.163Z,1744129185.163 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T16:19:45.163Z,1744129185.163 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T16:19:47.164Z,1744129187.164 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161922.00,A,3648.16642,N,12147.28342,W,0.078,158.00,080425,,,D*7E 2025-04-08T16:19:47.166Z,1744129187.166 [NAL9602](INFO): GPS fix at 20250408T161922: (36.802774, -121.788057) 2025-04-08T16:19:47.177Z,1744129187.177 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T16:19:47.177Z,1744129187.177 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T16:19:54.800Z,1744129194.800 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T152204/Courier0028.lzma 2025-04-08T16:19:55.803Z,1744129195.803 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0028.lzma.bak 2025-04-08T16:19:55.803Z,1744129195.803 [DataOverHttps](INFO): SBD MOMSN=24575921 2025-04-08T16:20:13.454Z,1744129213.454 [DataOverHttps](INFO): Sending 507 bytes from file Logs/20250408T152204/Express0029.lzma 2025-04-08T16:20:14.454Z,1744129214.454 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0029.lzma.bak 2025-04-08T16:20:14.455Z,1744129214.455 [DataOverHttps](INFO): SBD MOMSN=24575925 2025-04-08T16:20:16.278Z,1744129216.278 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T16:20:16.278Z,1744129216.278 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T16:20:16.278Z,1744129216.278 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T16:20:17.886Z,1744129217.886 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-04-08T16:20:17.969Z,1744129217.969 [NAL9602](ERROR): received: +CSQ:0 OK211, 2, 0, 0, 0 OK 2025-04-08T16:20:43.742Z,1744129243.742 [NAL9602](INFO): SBD MO Status=2, MOMSN=19211, MT Status=2, MTMSN=0 2025-04-08T16:20:43.742Z,1744129243.742 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-08T16:21:28.183Z,1744129288.183 [NAL9602](INFO): SBD MO Status=0, MOMSN=19211, MT Status=0, MTMSN=0 2025-04-08T16:21:28.183Z,1744129288.183 [NAL9602](INFO): No messages in MT queue 2025-04-08T16:21:58.903Z,1744129318.903 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-08T16:22:20.749Z,1744129340.749 [CBIT](INFO): Clearing failed state for component DropWeight 2025-04-08T16:22:20.749Z,1744129340.749 [DropWeight] No Fault, FailCount= 1 2025-04-08T16:25:16.890Z,1744129516.890 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T16:25:16.890Z,1744129516.890 [Default:CheckIn:C.Wait] Stopped 2025-04-08T16:25:16.890Z,1744129516.890 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T16:25:16.890Z,1744129516.890 [Default:CheckIn:D] Running Loop=1 2025-04-08T16:25:17.307Z,1744129517.307 [Default:CheckIn:D] Stopped 2025-04-08T16:25:17.307Z,1744129517.307 [Default:CheckIn:E] Running Loop=1 2025-04-08T16:25:17.696Z,1744129517.696 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.910958 min 2025-04-08T16:25:17.696Z,1744129517.696 [Default:CheckIn:E] Stopped 2025-04-08T16:25:17.696Z,1744129517.696 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T16:25:17.696Z,1744129517.696 [Default:CheckIn] Stopped 2025-04-08T16:25:17.696Z,1744129517.696 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T16:25:17.697Z,1744129517.697 [Default:CheckIn](INFO): Running loop #10 2025-04-08T16:25:17.697Z,1744129517.697 [Default:CheckIn] Running Loop=10 2025-04-08T16:25:17.697Z,1744129517.697 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T16:25:17.697Z,1744129517.697 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T16:25:19.704Z,1744129519.704 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162455.00,A,3648.16806,N,12147.28523,W,0.136,226.26,080425,,,D*7A 2025-04-08T16:25:19.706Z,1744129519.706 [NAL9602](INFO): GPS fix at 20250408T162455: (36.802801, -121.788087) 2025-04-08T16:25:19.718Z,1744129519.718 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T16:25:19.718Z,1744129519.718 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T16:25:25.360Z,1744129525.360 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+18.0,0000.0,1489.0,000 2025-04-08T16:25:27.804Z,1744129527.804 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T152204/Courier0031.lzma 2025-04-08T16:25:28.806Z,1744129528.806 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0031.lzma.bak 2025-04-08T16:25:28.807Z,1744129528.807 [DataOverHttps](INFO): SBD MOMSN=24575960 2025-04-08T16:25:46.089Z,1744129546.089 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20250408T152204/Express0032.lzma 2025-04-08T16:25:47.091Z,1744129547.091 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0032.lzma.bak 2025-04-08T16:25:47.091Z,1744129547.091 [DataOverHttps](INFO): SBD MOMSN=24575998 2025-04-08T16:25:48.814Z,1744129548.814 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T16:25:48.815Z,1744129548.815 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T16:25:48.815Z,1744129548.815 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T16:26:33.177Z,1744129593.177 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:26:33.264Z,1744129593.264 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:26:37.729Z,1744129597.729 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.001423 CHAN A1 (24V): 0.009849 CHAN A2 (12V): -0.021623 CHAN A3 (5V): -0.037594 CHAN B0 (3.3V): -0.021742 CHAN B1 (3.15aV): -0.004075 CHAN B2 (3.15bV): -0.002486 CHAN B3 (GND): -0.005660 OPEN: 0.012304 Full Scale: +/- 1 mA 2025-04-08T16:26:52.442Z,1744129612.442 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:26:52.717Z,1744129612.717 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:26:57.107Z,1744129617.107 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.000584 CHAN A1 (24V): 0.014147 CHAN A2 (12V): -0.016514 CHAN A3 (5V): -0.057670 CHAN B0 (3.3V): -0.006343 CHAN B1 (3.15aV): -0.004121 CHAN B2 (3.15bV): -0.002355 CHAN B3 (GND): -0.010820 OPEN: 0.012462 Full Scale: +/- 1 mA 2025-04-08T16:27:05.361Z,1744129625.361 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:27:05.598Z,1744129625.598 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:27:10.064Z,1744129630.064 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.000979 CHAN A1 (24V): 0.013726 CHAN A2 (12V): -0.015228 CHAN A3 (5V): -0.038339 CHAN B0 (3.3V): -0.008596 CHAN B1 (3.15aV): -0.003651 CHAN B2 (3.15bV): -0.002594 CHAN B3 (GND): -0.007134 OPEN: 0.012334 Full Scale: +/- 1 mA 2025-04-08T16:27:11.613Z,1744129631.613 [NAL9602](INFO): SBD MO Status=0, MOMSN=19212, MT Status=0, MTMSN=0 2025-04-08T16:27:11.614Z,1744129631.614 [NAL9602](INFO): No messages in MT queue 2025-04-08T16:27:35.377Z,1744129655.377 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:27:35.472Z,1744129655.472 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:27:40.102Z,1744129660.102 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.005736 CHAN A1 (24V): 0.021959 CHAN A2 (12V): -0.173575 CHAN A3 (5V): -0.038991 CHAN B0 (3.3V): -0.009445 CHAN B1 (3.15aV): -0.003394 CHAN B2 (3.15bV): -0.002199 CHAN B3 (GND): -0.005891 OPEN: 0.012203 Full Scale: +/- 1 mA 2025-04-08T16:27:42.086Z,1744129662.086 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-08T16:27:50.053Z,1744129670.053 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:27:50.201Z,1744129670.201 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:27:54.703Z,1744129674.703 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.000883 CHAN A1 (24V): 0.015630 CHAN A2 (12V): -0.015813 CHAN A3 (5V): -0.050054 CHAN B0 (3.3V): -0.010377 CHAN B1 (3.15aV): -0.009359 CHAN B2 (3.15bV): -0.002261 CHAN B3 (GND): -0.012595 OPEN: 0.012050 Full Scale: +/- 1 mA 2025-04-08T16:27:58.249Z,1744129678.249 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:27:58.414Z,1744129678.414 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:28:02.753Z,1744129682.753 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.027322 CHAN A1 (24V): 0.009889 CHAN A2 (12V): -0.012329 CHAN A3 (5V): -0.044491 CHAN B0 (3.3V): -0.007661 CHAN B1 (3.15aV): -0.003185 CHAN B2 (3.15bV): -0.002553 CHAN B3 (GND): -0.006965 OPEN: 0.012563 Full Scale: +/- 1 mA 2025-04-08T16:28:06.066Z,1744129686.066 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:28:06.373Z,1744129686.373 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:28:10.833Z,1744129690.833 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.002183 CHAN A1 (24V): 0.007763 CHAN A2 (12V): -0.024313 CHAN A3 (5V): -0.035490 CHAN B0 (3.3V): -0.008823 CHAN B1 (3.15aV): -0.003385 CHAN B2 (3.15bV): -0.002186 CHAN B3 (GND): -0.005363 OPEN: 0.012540 Full Scale: +/- 1 mA 2025-04-08T16:30:16.886Z,1744129816.886 [DVL_micro](ERROR): Failed to parse: :SA,-08.36,-23.09,269.5 2025-04-08T16:30:49.271Z,1744129849.271 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-08T16:30:49.271Z,1744129849.271 [Default:CheckIn:C.Wait] Stopped 2025-04-08T16:30:49.271Z,1744129849.271 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-08T16:30:49.271Z,1744129849.271 [Default:CheckIn:D] Running Loop=1 2025-04-08T16:30:49.633Z,1744129849.633 [Default:CheckIn:D] Stopped 2025-04-08T16:30:49.633Z,1744129849.633 [Default:CheckIn:E] Running Loop=1 2025-04-08T16:30:50.037Z,1744129850.037 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.449715 min 2025-04-08T16:30:50.037Z,1744129850.037 [Default:CheckIn:E] Stopped 2025-04-08T16:30:50.037Z,1744129850.037 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-08T16:30:50.037Z,1744129850.037 [Default:CheckIn] Stopped 2025-04-08T16:30:50.037Z,1744129850.037 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-08T16:30:50.038Z,1744129850.038 [Default:CheckIn](INFO): Running loop #11 2025-04-08T16:30:50.038Z,1744129850.038 [Default:CheckIn] Running Loop=11 2025-04-08T16:30:50.038Z,1744129850.038 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-08T16:30:50.038Z,1744129850.038 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-08T16:30:52.040Z,1744129852.040 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163027.00,A,3648.16434,N,12147.27976,W,0.136,120.08,080425,,,D*7D 2025-04-08T16:30:52.046Z,1744129852.046 [NAL9602](INFO): GPS fix at 20250408T163027: (36.802739, -121.787996) 2025-04-08T16:30:52.081Z,1744129852.081 [Default:CheckIn:Read_GPS] Stopped 2025-04-08T16:30:52.081Z,1744129852.081 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-08T16:31:06.169Z,1744129866.169 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T152204/Courier0034.lzma 2025-04-08T16:31:07.171Z,1744129867.171 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0034.lzma.bak 2025-04-08T16:31:07.171Z,1744129867.171 [DataOverHttps](INFO): SBD MOMSN=24576032 2025-04-08T16:31:24.594Z,1744129884.594 [DataOverHttps](INFO): Sending 653 bytes from file Logs/20250408T152204/Express0035.lzma 2025-04-08T16:31:25.595Z,1744129885.595 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0035.lzma.bak 2025-04-08T16:31:25.595Z,1744129885.595 [DataOverHttps](INFO): SBD MOMSN=24576036 2025-04-08T16:31:27.289Z,1744129887.289 [Default:CheckIn:Read_Iridium] Stopped 2025-04-08T16:31:27.289Z,1744129887.289 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-08T16:31:27.289Z,1744129887.289 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-08T16:32:21.165Z,1744129941.165 [CommandExec](IMPORTANT): got command gfscan 2025-04-08T16:32:21.498Z,1744129941.498 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-08T16:32:25.977Z,1744129945.977 [GFScanner](IM