2025-04-08T17:06:17.326Z,1744131977.326 [Supervisor](DEBUG): Initializing supervisor.
2025-04-08T17:06:17.330Z,1744131977.330 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-04-08T17:06:17.330Z,1744131977.330 [SyncHandler](INFO): Protected caller Thread ID is 831
2025-04-08T17:06:17.331Z,1744131977.331 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-04-08T17:06:17.332Z,1744131977.332 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-04-08T17:06:17.332Z,1744131977.332 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 832
2025-04-08T17:06:17.336Z,1744131977.336 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-04-08T17:06:17.356Z,1744131977.356 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-04-08T17:06:17.357Z,1744131977.357 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-04-08T17:06:17.358Z,1744131977.358 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 833
2025-04-08T17:06:17.362Z,1744131977.362 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-04-08T17:06:17.363Z,1744131977.363 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-04-08T17:06:17.363Z,1744131977.363 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 834
2025-04-08T17:06:17.366Z,1744131977.366 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-04-08T17:06:17.367Z,1744131977.367 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-04-08T17:06:17.367Z,1744131977.367 [logger ThreadHandler](INFO): Protected caller Thread ID is 835
2025-04-08T17:06:17.371Z,1744131977.371 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-04-08T17:06:17.371Z,1744131977.371 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-04-08T17:06:17.377Z,1744131977.377 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-04-08T17:06:17.483Z,1744131977.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-04-08T17:06:17.485Z,1744131977.485 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-04-08T17:06:17.720Z,1744131977.720 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-04-08T17:06:17.722Z,1744131977.722 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-04-08T17:06:18.004Z,1744131978.004 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-04-08T17:06:18.006Z,1744131978.006 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-04-08T17:06:18.123Z,1744131978.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-04-08T17:06:18.125Z,1744131978.125 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-04-08T17:06:18.900Z,1744131978.900 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-04-08T17:06:18.901Z,1744131978.901 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-04-08T17:06:19.421Z,1744131979.421 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-04-08T17:06:19.421Z,1744131979.421 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-04-08T17:06:19.989Z,1744131979.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-04-08T17:06:19.989Z,1744131979.989 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-04-08T17:06:20.421Z,1744131980.421 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-04-08T17:06:20.423Z,1744131980.423 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-04-08T17:06:20.784Z,1744131980.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-04-08T17:06:20.785Z,1744131980.785 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-04-08T17:06:21.471Z,1744131981.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-04-08T17:06:21.472Z,1744131981.472 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-04-08T17:06:21.709Z,1744131981.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-04-08T17:06:21.711Z,1744131981.711 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-04-08T17:06:21.862Z,1744131981.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-04-08T17:06:21.863Z,1744131981.863 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-04-08T17:06:21.956Z,1744131981.956 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-04-08T17:06:22.046Z,1744131982.046 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-04-08T17:06:22.248Z,1744131982.248 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-04-08T17:06:22.250Z,1744131982.250 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-04-08T17:06:22.505Z,1744131982.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-04-08T17:06:22.507Z,1744131982.507 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-04-08T17:06:22.509Z,1744131982.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-04-08T17:06:22.604Z,1744131982.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-04-08T17:06:22.881Z,1744131982.881 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-04-08T17:06:22.882Z,1744131982.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-04-08T17:06:22.977Z,1744131982.977 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-04-08T17:06:23.155Z,1744131983.155 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-04-08T17:06:23.265Z,1744131983.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-04-08T17:06:23.413Z,1744131983.413 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-04-08T17:06:23.535Z,1744131983.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-04-08T17:06:23.639Z,1744131983.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-04-08T17:06:23.809Z,1744131983.809 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-04-08T17:06:23.916Z,1744131983.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-04-08T17:06:24.012Z,1744131984.012 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-04-08T17:06:24.119Z,1744131984.119 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-04-08T17:06:24.216Z,1744131984.216 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-04-08T17:06:24.239Z,1744131984.239 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-04-08T17:06:24.460Z,1744131984.460 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-04-08T17:06:24.460Z,1744131984.460 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-04-08T17:06:24.653Z,1744131984.653 [BuoyancyServo] Loaded
2025-04-08T17:06:24.654Z,1744131984.654 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-04-08T17:06:24.677Z,1744131984.677 [ElevatorServo] Loaded
2025-04-08T17:06:24.677Z,1744131984.677 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-04-08T17:06:24.699Z,1744131984.699 [MassServo] Loaded
2025-04-08T17:06:24.700Z,1744131984.700 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-04-08T17:06:24.722Z,1744131984.722 [RudderServo] Loaded
2025-04-08T17:06:24.722Z,1744131984.722 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-04-08T17:06:24.740Z,1744131984.740 [ThrusterHE] Loaded
2025-04-08T17:06:24.740Z,1744131984.740 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-04-08T17:06:24.741Z,1744131984.741 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-04-08T17:06:24.742Z,1744131984.742 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-04-08T17:06:24.942Z,1744131984.942 [SBIT](DEBUG): Construct Startup Built In Test.
2025-04-08T17:06:24.957Z,1744131984.957 [SBIT] Loaded
2025-04-08T17:06:24.957Z,1744131984.957 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-04-08T17:06:24.960Z,1744131984.960 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-04-08T17:06:24.981Z,1744131984.981 [IBIT] Loaded
2025-04-08T17:06:24.981Z,1744131984.981 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-04-08T17:06:24.986Z,1744131984.986 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-04-08T17:06:25.177Z,1744131985.177 [CBIT] Loaded
2025-04-08T17:06:25.177Z,1744131985.177 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-04-08T17:06:25.208Z,1744131985.208 [GFScanner] Loaded
2025-04-08T17:06:25.209Z,1744131985.209 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-04-08T17:06:25.209Z,1744131985.209 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-04-08T17:06:25.210Z,1744131985.210 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-04-08T17:06:25.424Z,1744131985.424 [CTD_Seabird] Loaded
2025-04-08T17:06:25.424Z,1744131985.424 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-04-08T17:06:25.425Z,1744131985.425 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406834E0
2025-04-08T17:06:25.426Z,1744131985.426 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 923
2025-04-08T17:06:25.461Z,1744131985.461 [ESPComponent] Loaded
2025-04-08T17:06:25.461Z,1744131985.461 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-04-08T17:06:25.483Z,1744131985.483 [PAR_Licor] Loaded
2025-04-08T17:06:25.483Z,1744131985.483 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-04-08T17:06:25.528Z,1744131985.528 [WetLabsBB2FL] Loaded
2025-04-08T17:06:25.528Z,1744131985.528 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-04-08T17:06:25.529Z,1744131985.529 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B34E0
2025-04-08T17:06:25.529Z,1744131985.529 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 924
2025-04-08T17:06:25.530Z,1744131985.530 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-04-08T17:06:25.532Z,1744131985.532 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-04-08T17:06:25.604Z,1744131985.604 [DepthRateCalculator] Loaded
2025-04-08T17:06:25.604Z,1744131985.604 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-04-08T17:06:25.609Z,1744131985.609 [PitchRateCalculator] Loaded
2025-04-08T17:06:25.610Z,1744131985.610 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-04-08T17:06:25.620Z,1744131985.620 [SpeedCalculator] Loaded
2025-04-08T17:06:25.620Z,1744131985.620 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-04-08T17:06:25.625Z,1744131985.625 [YawRateCalculator] Loaded
2025-04-08T17:06:25.625Z,1744131985.625 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-04-08T17:06:25.645Z,1744131985.645 [ElevatorOffsetCalculator] Loaded
2025-04-08T17:06:25.645Z,1744131985.645 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-04-08T17:06:25.646Z,1744131985.646 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-04-08T17:06:25.646Z,1744131985.646 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-04-08T17:06:25.815Z,1744131985.815 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-04-08T17:06:25.816Z,1744131985.816 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-04-08T17:06:26.489Z,1744131986.489 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-04-08T17:06:26.520Z,1744131986.520 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-04-08T17:06:26.662Z,1744131986.662 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-04-08T17:06:26.663Z,1744131986.663 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-04-08T17:06:26.677Z,1744131986.677 [NavChart] Loaded
2025-04-08T17:06:26.677Z,1744131986.677 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-04-08T17:06:26.682Z,1744131986.682 [UniversalFixResidualReporter] Loaded
2025-04-08T17:06:26.683Z,1744131986.683 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-04-08T17:06:26.683Z,1744131986.683 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-04-08T17:06:26.684Z,1744131986.684 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-04-08T17:06:27.568Z,1744131987.568 [AHRS_M2] Loaded
2025-04-08T17:06:27.568Z,1744131987.568 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-04-08T17:06:27.821Z,1744131987.821 [BackseatComponent] Loaded
2025-04-08T17:06:27.821Z,1744131987.821 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-04-08T17:06:27.822Z,1744131987.822 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0
2025-04-08T17:06:27.823Z,1744131987.823 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925
2025-04-08T17:06:27.826Z,1744131987.826 [LcmUniversalReporter] Loaded
2025-04-08T17:06:27.826Z,1744131987.826 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-04-08T17:06:28.559Z,1744131988.559 [BPC1] Loaded
2025-04-08T17:06:28.559Z,1744131988.559 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-04-08T17:06:28.656Z,1744131988.656 [DAT] Loaded
2025-04-08T17:06:28.656Z,1744131988.656 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-04-08T17:06:28.657Z,1744131988.657 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0
2025-04-08T17:06:28.657Z,1744131988.657 [DAT ThreadHandler](INFO): Protected caller Thread ID is 926
2025-04-08T17:06:28.799Z,1744131988.799 [DataOverHttps] Loaded
2025-04-08T17:06:28.799Z,1744131988.799 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-04-08T17:06:28.800Z,1744131988.800 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0
2025-04-08T17:06:28.801Z,1744131988.801 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 927
2025-04-08T17:06:28.824Z,1744131988.824 [Depth_Keller] Loaded
2025-04-08T17:06:28.824Z,1744131988.824 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-04-08T17:06:28.829Z,1744131988.829 [DropWeight] Loaded
2025-04-08T17:06:28.830Z,1744131988.830 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-04-08T17:06:28.870Z,1744131988.870 [DVL_micro] Loaded
2025-04-08T17:06:28.870Z,1744131988.870 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2025-04-08T17:06:28.933Z,1744131988.933 [NAL9602] Loaded
2025-04-08T17:06:28.933Z,1744131988.933 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-04-08T17:06:28.959Z,1744131988.959 [Onboard] Loaded
2025-04-08T17:06:28.960Z,1744131988.960 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-04-08T17:06:28.961Z,1744131988.961 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0
2025-04-08T17:06:28.961Z,1744131988.961 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 928
2025-04-08T17:06:28.967Z,1744131988.967 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2025-04-08T17:06:28.981Z,1744131988.981 [PowerOnly] Loaded
2025-04-08T17:06:28.981Z,1744131988.981 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-04-08T17:06:28.995Z,1744131988.995 [Power24vConverter] Loaded
2025-04-08T17:06:28.995Z,1744131988.995 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-04-08T17:06:29.011Z,1744131989.011 [Radio_Surface] Loaded
2025-04-08T17:06:29.012Z,1744131989.012 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-04-08T17:06:29.013Z,1744131989.013 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B3F4E0
2025-04-08T17:06:29.013Z,1744131989.013 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 929
2025-04-08T17:06:29.029Z,1744131989.029 [Sonardyne_Nano] Loaded
2025-04-08T17:06:29.029Z,1744131989.029 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-04-08T17:06:29.030Z,1744131989.030 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-04-08T17:06:29.030Z,1744131989.030 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-04-08T17:06:29.117Z,1744131989.117 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-04-08T17:06:29.118Z,1744131989.118 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-04-08T17:06:29.191Z,1744131989.191 [VerticalControl](DEBUG): Construct VerticalControl.
2025-04-08T17:06:29.243Z,1744131989.243 [VerticalControl] Loaded
2025-04-08T17:06:29.244Z,1744131989.244 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-04-08T17:06:29.247Z,1744131989.247 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-04-08T17:06:29.291Z,1744131989.291 [HorizontalControl] Loaded
2025-04-08T17:06:29.291Z,1744131989.291 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-04-08T17:06:29.293Z,1744131989.293 [SpeedControl](DEBUG): Construct SpeedControl.
2025-04-08T17:06:29.295Z,1744131989.295 [SpeedControl] Loaded
2025-04-08T17:06:29.295Z,1744131989.295 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-04-08T17:06:29.298Z,1744131989.298 [LoopControl](DEBUG): Construct LoopControl.
2025-04-08T17:06:29.299Z,1744131989.299 [LoopControl] Loaded
2025-04-08T17:06:29.299Z,1744131989.299 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-04-08T17:06:29.299Z,1744131989.299 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-04-08T17:06:29.300Z,1744131989.300 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-04-08T17:06:29.316Z,1744131989.316 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-04-08T17:06:29.316Z,1744131989.316 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-04-08T17:06:29.731Z,1744131989.731 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-04-08T17:06:29.737Z,1744131989.737 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-04-08T17:06:29.740Z,1744131989.740 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-04-08T17:06:29.751Z,1744131989.751 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-04-08T17:06:29.752Z,1744131989.752 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0
2025-04-08T17:06:29.753Z,1744131989.753 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 930
2025-04-08T17:06:29.757Z,1744131989.757 [Supervisor](INFO): Main Thread ID is 824
2025-04-08T17:06:29.757Z,1744131989.757 [Supervisor](DEBUG): Running supervisor.
2025-04-08T17:06:29.758Z,1744131989.758 [CommandExec ThreadHandler](INFO): Handler Thread ID is 931
2025-04-08T17:06:29.758Z,1744131989.758 [CommandExec](INFO): Initializing the command executive.
2025-04-08T17:06:29.760Z,1744131989.760 [CommandLine ThreadHandler](INFO): Handler Thread ID is 932
2025-04-08T17:06:29.762Z,1744131989.762 [controlThread ThreadHandler](INFO): Handler Thread ID is 933
2025-04-08T17:06:29.762Z,1744131989.762 [controlThread](DEBUG): Initializing ControlThread
2025-04-08T17:06:29.764Z,1744131989.764 [SBIT](INFO): Initialize SBIT Component.
2025-04-08T17:06:29.765Z,1744131989.765 [SBIT](IMPORTANT): git: 2025-03-26-1-g1815535cc
2025-04-08T17:06:29.765Z,1744131989.765 [SBIT](INFO): git hash: 1815535cca105e464bdb7831f6233b5043f0283f
2025-04-08T17:06:29.765Z,1744131989.765 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-04-08T17:06:29.767Z,1744131989.767 [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-08T17:06:29.768Z,1744131989.768 [SBIT](INFO): Beginning SBIT in 69.000000 seconds.
2025-04-08T17:06:29.768Z,1744131989.768 [IBIT](INFO): Initialize IBIT Component.
2025-04-08T17:06:29.769Z,1744131989.769 [CBIT](DEBUG): Initialize CBIT Component.
2025-04-08T17:06:29.770Z,1744131989.770 [logger ThreadHandler](INFO): Handler Thread ID is 934
2025-04-08T17:06:29.780Z,1744131989.780 [CBIT](DEBUG): Initialized mux pins.
2025-04-08T17:06:29.780Z,1744131989.780 [CBIT](DEBUG): Initializing the watchdog timer.
2025-04-08T17:06:29.788Z,1744131989.788 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 935
2025-04-08T17:06:29.789Z,1744131989.789 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-04-08T17:06:29.794Z,1744131989.794 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 937
2025-04-08T17:06:29.796Z,1744131989.796 [WetLabsBB2FL](INFO): Powering up
2025-04-08T17:06:29.797Z,1744131989.797 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 939
2025-04-08T17:06:29.804Z,1744131989.804 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-04-08T17:06:29.804Z,1744131989.804 [CBIT](DEBUG): Initializing heartbeat.
2025-04-08T17:06:29.805Z,1744131989.805 [DAT ThreadHandler](INFO): Handler Thread ID is 940
2025-04-08T17:06:29.806Z,1744131989.806 [DAT](INFO): Powering up
2025-04-08T17:06:29.806Z,1744131989.806 [DAT](DEBUG): Initializing DAT.
2025-04-08T17:06:29.809Z,1744131989.809 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 942
2025-04-08T17:06:29.810Z,1744131989.810 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-04-08T17:06:29.832Z,1744131989.832 [Onboard ThreadHandler](INFO): Handler Thread ID is 943
2025-04-08T17:06:29.849Z,1744131989.849 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 944
2025-04-08T17:06:29.872Z,1744131989.872 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 945
2025-04-08T17:06:29.876Z,1744131989.876 [CBIT](DEBUG): Deactivating emergency mode.
2025-04-08T17:06:29.881Z,1744131989.881 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-04-08T17:06:29.881Z,1744131989.881 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-04-08T17:06:29.881Z,1744131989.881 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-04-08T17:06:29.881Z,1744131989.881 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-04-08T17:06:29.881Z,1744131989.881 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-04-08T17:06:29.881Z,1744131989.881 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-04-08T17:06:29.882Z,1744131989.882 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-04-08T17:06:29.882Z,1744131989.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-04-08T17:06:29.916Z,1744131989.916 [CBIT](DEBUG): Backplane powered.
2025-04-08T17:06:29.916Z,1744131989.916 [GFScanner](DEBUG): Initializing GFScanner
2025-04-08T17:06:29.916Z,1744131989.916 [GFScanner](DEBUG): Deactivating GF circuits.
2025-04-08T17:06:29.924Z,1744131989.924 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-04-08T17:06:29.925Z,1744131989.925 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-04-08T17:06:29.925Z,1744131989.925 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-04-08T17:06:29.925Z,1744131989.925 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-04-08T17:06:29.926Z,1744131989.926 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-04-08T17:06:29.927Z,1744131989.927 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-04-08T17:06:29.927Z,1744131989.927 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-04-08T17:06:29.931Z,1744131989.931 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-04-08T17:06:29.937Z,1744131989.937 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-04-08T17:06:29.937Z,1744131989.937 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-04-08T17:06:29.938Z,1744131989.938 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-04-08T17:06:29.938Z,1744131989.938 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-04-08T17:06:29.939Z,1744131989.939 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-04-08T17:06:29.939Z,1744131989.939 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-04-08T17:06:29.961Z,1744131989.961 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-04-08T17:06:30.014Z,1744131990.014 [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-04-08T17:06:30.031Z,1744131990.031 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-08T17:06:30.061Z,1744131990.061 [DAT](INFO): Using elevation to construct direction to contact in vehicle frame.
2025-04-08T17:06:30.075Z,1744131990.075 [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-08T17:06:30.096Z,1744131990.096 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-04-08T17:06:30.096Z,1744131990.096 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-04-08T17:06:30.099Z,1744131990.099 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-04-08T17:06:30.256Z,1744131990.256 [Radio_Surface](INFO): Powering up
2025-04-08T17:06:30.418Z,1744131990.418 [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-04-08T17:06:30.440Z,1744131990.440 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-04-08T17:06:30.441Z,1744131990.441 [Default:A.Wait](DEBUG): Construct Wait.
2025-04-08T17:06:30.444Z,1744131990.444 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-08T17:06:30.489Z,1744131990.489 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-04-08T17:06:30.492Z,1744131990.492 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-04-08T17:06:30.514Z,1744131990.514 [Default:E.Execute](DEBUG): Construct Execute.
2025-04-08T17:06:30.517Z,1744131990.517 [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-08T17:06:30.529Z,1744131990.529 [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-08T17:06:30.554Z,1744131990.554 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-04-08T17:06:30.712Z,1744131990.712 [Depth_Keller](INFO): Initializing.
2025-04-08T17:06:30.718Z,1744131990.718 [Power24vConverter](INFO): Powering up.
2025-04-08T17:06:30.718Z,1744131990.718 [Sonardyne_Nano](INFO): Initializing.
2025-04-08T17:06:30.744Z,1744131990.744 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-04-08T17:06:30.782Z,1744131990.782 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-04-08T17:06:30.788Z,1744131990.788 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-04-08T17:06:30.789Z,1744131990.789 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-04-08T17:06:30.797Z,1744131990.797 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-04-08T17:06:30.798Z,1744131990.798 [MassServo](DEBUG): Initializing EZServoServo.
2025-04-08T17:06:30.804Z,1744131990.804 [MassServo](DEBUG): Initializing MassServo.
2025-04-08T17:06:30.805Z,1744131990.805 [RudderServo](DEBUG): Initializing EZServoServo.
2025-04-08T17:06:30.813Z,1744131990.813 [RudderServo](DEBUG): Initializing RudderServo.
2025-04-08T17:06:30.814Z,1744131990.814 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-04-08T17:06:30.820Z,1744131990.820 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-04-08T17:06:30.975Z,1744131990.975 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2025-04-08T17:06:30.975Z,1744131990.975 [DropWeight] Hardware Fault, FailCount= 1
2025-04-08T17:06:30.975Z,1744131990.975 [DropWeight](ERROR): Hardware Fault
2025-04-08T17:06:31.003Z,1744131991.003 [CommandExec](FAULT): Scheduling is paused
2025-04-08T17:06:31.003Z,1744131991.003 [CBIT](INFO): Critical error at 20250408T170630
2025-04-08T17:06:31.003Z,1744131991.003 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-04-08T17:06:31.014Z,1744131991.014 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-04-08T17:06:31.015Z,1744131991.015 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-04-08T17:06:31.369Z,1744131991.369 [CBIT](INFO): Critical error at 20250408T170631
2025-04-08T17:06:32.408Z,1744131992.408 [WetLabsBB2FL](INFO): Powering down
2025-04-08T17:06:32.971Z,1744131992.971 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-04-08T17:06:34.217Z,1744131994.217 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-04-08T17:06:36.441Z,1744131996.441 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-04-08T17:06:41.905Z,1744132001.905 [DAT](INFO): DAT read: 

2025-04-08T17:06:41.906Z,1744132001.906 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2025-04-08T17:06:43.669Z,1744132003.669 [DAT](INFO): DAT read: MF Frequency Band

2025-04-08T17:06:43.670Z,1744132003.670 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2025-04-08T17:06:43.671Z,1744132003.671 [DAT](INFO): DAT read: Apr  8 2025 17:06:37 

2025-04-08T17:06:44.679Z,1744132004.679 [DAT](INFO): DAT read: Features enabled [Bearing]

2025-04-08T17:06:44.929Z,1744132004.929 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2025-04-08T17:06:44.930Z,1744132004.930 [DAT](INFO): commRate: 1200
2025-04-08T17:06:46.996Z,1744132006.996 [DAT](INFO): entering command mode
2025-04-08T17:06:47.196Z,1744132007.196 [DAT](INFO): DAT read: 

2025-04-08T17:06:47.197Z,1744132007.197 [DAT](INFO): DAT read: user:1>

2025-04-08T17:06:47.197Z,1744132007.197 [DAT](INFO): setting verbose to 3
2025-04-08T17:06:47.449Z,1744132007.449 [DAT](INFO): DAT read: user:1>

2025-04-08T17:06:47.450Z,1744132007.450 [DAT](INFO): DAT read: Verbose         | 3           

2025-04-08T17:06:47.450Z,1744132007.450 [DAT](INFO): set verbose to 3
2025-04-08T17:06:47.450Z,1744132007.450 [DAT](INFO): setting DatVerbose to 27440
2025-04-08T17:06:47.701Z,1744132007.701 [DAT](INFO): DAT read: user:2>

2025-04-08T17:06:47.702Z,1744132007.702 [DAT](INFO): DAT read: DatVerbose      | 27440       

2025-04-08T17:06:47.702Z,1744132007.702 [DAT](INFO): set DatVerbose to 27440
2025-04-08T17:06:47.702Z,1744132007.702 [DAT](INFO): setting transmit power to 8
2025-04-08T17:06:47.953Z,1744132007.953 [DAT](INFO): DAT read: user:3>

2025-04-08T17:06:47.954Z,1744132007.954 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2025-04-08T17:06:47.954Z,1744132007.954 [DAT](INFO): set transmit power to 8
2025-04-08T17:06:47.954Z,1744132007.954 [DAT](INFO): setting local address to 5
2025-04-08T17:06:48.205Z,1744132008.205 [DAT](INFO): DAT read: user:4>

2025-04-08T17:06:48.206Z,1744132008.206 [DAT](INFO): DAT read: LocalAddr       | 5           

2025-04-08T17:06:48.206Z,1744132008.206 [DAT](INFO): set local address to 5
2025-04-08T17:06:48.207Z,1744132008.207 [DAT](INFO): Setting time to: 17:6:48 And date to:4/8/2025
2025-04-08T17:06:48.457Z,1744132008.457 [DAT](INFO): DAT read: user:5>

2025-04-08T17:06:48.458Z,1744132008.458 [DAT](INFO): DAT read: Tue Apr 8, 2025  17:06:48  

2025-04-08T17:06:48.458Z,1744132008.458 [DAT](INFO): Local DAT time set to Tue Apr 8, 2025  17:06:48  

2025-04-08T17:06:59.255Z,1744132019.255 [NAL9602](INFO): Powering up NAL9602
2025-04-08T17:07:10.168Z,1744132030.168 [NAL9602](INFO): NAL9602 initialized
2025-04-08T17:07:39.264Z,1744132059.264 [SBIT](IMPORTANT): Beginning Startup BIT
2025-04-08T17:07:39.269Z,1744132059.269 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:07:44.049Z,1744132064.049 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.063944
CHAN A1 (24V): 0.010312
CHAN A2 (12V): -0.006915
CHAN A3 (5V): -0.081468
CHAN B0 (3.3V): -0.009080
CHAN B1 (3.15aV): -0.003332
CHAN B2 (3.15bV): -0.002085
CHAN B3 (GND): -0.022353
OPEN: 0.012148
Full Scale: +/- 1 mA
2025-04-08T17:08:33.417Z,1744132113.417 [SBIT](IMPORTANT): SBIT PASSED
2025-04-08T17:08:33.417Z,1744132113.417 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-04-08T17:08:33.418Z,1744132113.418 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=1 bool;

2025-04-08T17:08:33.418Z,1744132113.418 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;

2025-04-08T17:08:33.418Z,1744132113.418 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2025-04-08T17:08:33.418Z,1744132113.418 [SBIT](IMPORTANT): BuoyancyServo.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): DropWeight.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): ElevatorServo.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): MassServo.loadAtStartup=1 bool;

2025-04-08T17:08:33.419Z,1744132113.419 [SBIT](IMPORTANT): NAL9602.loadAtStartup=1 bool;

2025-04-08T17:08:33.428Z,1744132113.428 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2025-04-08T17:08:33.428Z,1744132113.428 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool;

2025-04-08T17:08:33.428Z,1744132113.428 [SBIT](IMPORTANT): Radio_Surface.loadAtStartup=1 bool;

2025-04-08T17:08:33.428Z,1744132113.428 [SBIT](IMPORTANT): RudderServo.loadAtStartup=1 bool;

2025-04-08T17:08:33.428Z,1744132113.428 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2025-04-08T17:08:33.428Z,1744132113.428 [SBIT](IMPORTANT): ThrusterHE.loadAtStartup=1 bool;

2025-04-08T17:08:33.429Z,1744132113.429 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=209.04 cubic_centimeter;

2025-04-08T17:08:33.429Z,1744132113.429 [SBIT](IMPORTANT): VerticalControl.kdDepth=0.4 radian_per_second_per_meter;

2025-04-08T17:08:33.429Z,1744132113.429 [SBIT](IMPORTANT): VerticalControl.kpDepth=0.1 radian_per_meter;

2025-04-08T17:08:33.429Z,1744132113.429 [SBIT](IMPORTANT): VerticalControl.massDefault=12.4082 millimeter;

2025-04-08T17:08:33.429Z,1744132113.429 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=1 bool;

2025-04-08T17:08:33.713Z,1744132113.713 [MissionManager](IMPORTANT): Started mission Startup
2025-04-08T17:08:33.713Z,1744132113.713 [Startup] Running Loop=1
2025-04-08T17:08:33.713Z,1744132113.713 [Startup](DEBUG): Aggregate::initialize Startup
2025-04-08T17:08:33.713Z,1744132113.713 [Startup:A.GoToSurface] Running Loop=1
2025-04-08T17:08:33.713Z,1744132113.713 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-08T17:08:33.714Z,1744132113.714 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-08T17:08:33.714Z,1744132113.714 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-08T17:08:33.715Z,1744132113.715 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-08T17:08:33.715Z,1744132113.715 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-08T17:08:33.715Z,1744132113.715 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-08T17:08:33.720Z,1744132113.720 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-08T17:08:33.722Z,1744132113.722 [Startup:StartupSatComms] Running Loop=1
2025-04-08T17:08:33.722Z,1744132113.722 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-04-08T17:08:33.722Z,1744132113.722 [Startup:StartupSatComms:A] Running Loop=1
2025-04-08T17:08:34.125Z,1744132114.125 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-04-08T17:08:35.738Z,1744132115.738 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004865
2025-04-08T17:09:30.299Z,1744132170.299 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-04-08T17:09:30.299Z,1744132170.299 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-08T17:09:30.346Z,1744132170.346 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-08T17:09:30.807Z,1744132170.807 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-08T17:09:30.807Z,1744132170.807 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-04-08T17:09:33.954Z,1744132173.954 [Startup:StartupSatComms:A](INFO): Timed out from 2025-04-08T17:08:33.7Z
2025-04-08T17:09:33.954Z,1744132173.954 [Startup:StartupSatComms:A] Stopped
2025-04-08T17:09:33.954Z,1744132173.954 [Startup:StartupSatComms:B] Running Loop=1
2025-04-08T17:09:34.340Z,1744132174.340 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-08T17:09:41.685Z,1744132181.685 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250408T152204/Courier0040.lzma
2025-04-08T17:09:42.687Z,1744132182.687 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Courier0040.lzma.bak
2025-04-08T17:09:42.687Z,1744132182.687 [DataOverHttps](INFO): SBD MOMSN=24576438
2025-04-08T17:10:02.953Z,1744132202.953 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20250408T165514/Courier0000.lzma
2025-04-08T17:10:03.954Z,1744132203.954 [DataOverHttps](INFO): Moved sent file to Logs/20250408T165514/Courier0000.lzma.bak
2025-04-08T17:10:03.954Z,1744132203.954 [DataOverHttps](INFO): SBD MOMSN=24576443
2025-04-08T17:10:21.055Z,1744132221.055 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250408T165514/Courier0004.lzma
2025-04-08T17:10:22.058Z,1744132222.058 [DataOverHttps](INFO): Moved sent file to Logs/20250408T165514/Courier0004.lzma.bak
2025-04-08T17:10:22.058Z,1744132222.058 [DataOverHttps](INFO): SBD MOMSN=24576452
2025-04-08T17:10:34.123Z,1744132234.123 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-08T17:09:33.0Z
2025-04-08T17:10:34.123Z,1744132234.123 [Startup:StartupSatComms:B] Stopped
2025-04-08T17:10:34.123Z,1744132234.123 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-04-08T17:10:34.123Z,1744132234.123 [Startup:StartupSatComms] Stopped
2025-04-08T17:10:34.123Z,1744132234.123 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-04-08T17:10:34.125Z,1744132234.125 [Startup](INFO): Completed Startup
2025-04-08T17:10:34.125Z,1744132234.125 [MissionManager](INFO): Startup is completed.
2025-04-08T17:10:34.125Z,1744132234.125 [MissionManager](INFO): Uninitializing Mission Startup
2025-04-08T17:10:34.125Z,1744132234.125 [Startup] Stopped
2025-04-08T17:10:34.125Z,1744132234.125 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-04-08T17:10:34.125Z,1744132234.125 [Startup:A.GoToSurface] Stopped
2025-04-08T17:10:34.125Z,1744132234.125 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-08T17:10:34.545Z,1744132234.545 [MissionManager](IMPORTANT): Started mission Default
2025-04-08T17:10:34.545Z,1744132234.545 [Default] Running Loop=1
2025-04-08T17:10:34.545Z,1744132234.545 [Default](DEBUG): Aggregate::initialize Default
2025-04-08T17:10:34.545Z,1744132234.545 [Default:B.GoToSurface] Running Loop=1
2025-04-08T17:10:34.546Z,1744132234.546 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-08T17:10:34.546Z,1744132234.546 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-08T17:10:34.546Z,1744132234.546 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-08T17:10:34.546Z,1744132234.546 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-08T17:10:34.547Z,1744132234.547 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-08T17:10:34.547Z,1744132234.547 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-08T17:10:34.547Z,1744132234.547 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-08T17:10:34.548Z,1744132234.548 [Default:A.Wait] Running Loop=1
2025-04-08T17:10:34.548Z,1744132234.548 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:10:39.391Z,1744132239.391 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250408T170149/Courier0000.lzma
2025-04-08T17:10:40.393Z,1744132240.393 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170149/Courier0000.lzma.bak
2025-04-08T17:10:40.394Z,1744132240.394 [DataOverHttps](INFO): SBD MOMSN=24576454
2025-04-08T17:10:47.929Z,1744132247.929 [Default:A.Wait](INFO): Done Waiting.
2025-04-08T17:10:47.929Z,1744132247.929 [Default:A.Wait] Stopped
2025-04-08T17:10:47.929Z,1744132247.929 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:10:48.292Z,1744132248.292 [Default:CheckIn] Running Loop=1
2025-04-08T17:10:48.292Z,1744132248.292 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:10:48.293Z,1744132248.293 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:10:48.657Z,1744132248.657 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-04-08T17:12:13.134Z,1744132333.134 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-08T17:12:18.761Z,1744132338.761 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171154.00,A,3648.16598,N,12147.28311,W,0.097,325.69,080425,,,D*72
2025-04-08T17:12:18.764Z,1744132338.764 [NAL9602](INFO): GPS fix at 20250408T171154: (36.802766, -121.788052)
2025-04-08T17:12:18.775Z,1744132338.775 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:12:18.775Z,1744132338.775 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:12:19.195Z,1744132339.195 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-08T17:12:19.660Z,1744132339.660 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20250408T170617/Courier0000.lzma
2025-04-08T17:12:20.202Z,1744132340.202 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0000.lzma.bak
2025-04-08T17:12:20.202Z,1744132340.202 [DataOverHttps](INFO): SBD MOMSN=24576457
2025-04-08T17:12:33.041Z,1744132353.041 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:12:33.076Z,1744132353.076 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:12:37.712Z,1744132357.712 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.000452
CHAN A1 (24V): 0.009830
CHAN A2 (12V): -0.027690
CHAN A3 (5V): -0.027068
CHAN B0 (3.3V): -0.009571
CHAN B1 (3.15aV): -0.003436
CHAN B2 (3.15bV): -0.002276
CHAN B3 (GND): -0.003643
OPEN: 0.012236
Full Scale: +/- 1 mA
2025-04-08T17:12:39.556Z,1744132359.556 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250408T170617/Courier0004.lzma
2025-04-08T17:12:40.558Z,1744132360.558 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0004.lzma.bak
2025-04-08T17:12:40.558Z,1744132360.558 [DataOverHttps](INFO): SBD MOMSN=24576462
2025-04-08T17:12:51.238Z,1744132371.238 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-08T17:12:55.029Z,1744132375.029 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:12:55.349Z,1744132375.349 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:12:58.565Z,1744132378.565 [DataOverHttps](INFO): Sending 471 bytes from file Logs/20250408T152204/Express0038.lzma
2025-04-08T17:12:59.562Z,1744132379.562 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0038.lzma.bak
2025-04-08T17:12:59.562Z,1744132379.562 [DataOverHttps](INFO): SBD MOMSN=24576465
2025-04-08T17:12:59.759Z,1744132379.759 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.004801
CHAN A1 (24V): 0.050383
CHAN A2 (12V): -0.019609
CHAN A3 (5V): -0.036278
CHAN B0 (3.3V): -0.010719
CHAN B1 (3.15aV): -0.004240
CHAN B2 (3.15bV): -0.001684
CHAN B3 (GND): -0.006390
OPEN: 0.012415
Full Scale: +/- 1 mA
2025-04-08T17:13:04.977Z,1744132384.977 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-04-08T17:13:04.978Z,1744132384.978 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 5.
2025-04-08T17:13:04.988Z,1744132384.988 [BPC1](INFO): Received data from all battery sticks.
2025-04-08T17:13:05.673Z,1744132385.673 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:13:05.886Z,1744132385.886 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:13:10.263Z,1744132390.263 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.004382
CHAN A1 (24V): 0.008890
CHAN A2 (12V): -0.017162
CHAN A3 (5V): -0.029316
CHAN B0 (3.3V): -0.008435
CHAN B1 (3.15aV): -0.003298
CHAN B2 (3.15bV): -0.002621
CHAN B3 (GND): -0.004659
OPEN: 0.012265
Full Scale: +/- 1 mA
2025-04-08T17:13:16.223Z,1744132396.223 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250408T152204/Express0041.lzma
2025-04-08T17:13:17.226Z,1744132397.226 [DataOverHttps](INFO): Moved sent file to Logs/20250408T152204/Express0041.lzma.bak
2025-04-08T17:13:17.226Z,1744132397.226 [DataOverHttps](INFO): SBD MOMSN=24576472
2025-04-08T17:13:33.527Z,1744132413.527 [DataOverHttps](INFO): Sending 1012 bytes from file Logs/20250408T165514/Express0001.lzma
2025-04-08T17:13:34.523Z,1744132414.523 [DataOverHttps](INFO): Moved sent file to Logs/20250408T165514/Express0001.lzma.bak
2025-04-08T17:13:34.523Z,1744132414.523 [DataOverHttps](INFO): SBD MOMSN=24576474
2025-04-08T17:13:51.055Z,1744132431.055 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250408T165514/Express0005.lzma
2025-04-08T17:13:52.058Z,1744132432.058 [DataOverHttps](INFO): Moved sent file to Logs/20250408T165514/Express0005.lzma.bak
2025-04-08T17:13:52.058Z,1744132432.058 [DataOverHttps](INFO): SBD MOMSN=24576504
2025-04-08T17:14:11.588Z,1744132451.588 [DataOverHttps](INFO): Sending 636 bytes from file Logs/20250408T170149/Express0001.lzma
2025-04-08T17:14:12.586Z,1744132452.586 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170149/Express0001.lzma.bak
2025-04-08T17:14:12.586Z,1744132452.586 [DataOverHttps](INFO): SBD MOMSN=24576506
2025-04-08T17:14:29.645Z,1744132469.645 [DataOverHttps](INFO): Sending 1077 bytes from file Logs/20250408T170617/Express0001.lzma
2025-04-08T17:14:30.638Z,1744132470.638 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0001.lzma.bak
2025-04-08T17:14:30.638Z,1744132470.638 [DataOverHttps](INFO): SBD MOMSN=24576521
2025-04-08T17:14:47.040Z,1744132487.040 [DataOverHttps](INFO): Sending 415 bytes from file Logs/20250408T170617/Express0005.lzma
2025-04-08T17:14:48.042Z,1744132488.042 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0005.lzma.bak
2025-04-08T17:14:48.042Z,1744132488.042 [DataOverHttps](INFO): SBD MOMSN=24576559
2025-04-08T17:14:49.629Z,1744132489.629 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:14:49.629Z,1744132489.629 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:14:49.629Z,1744132489.629 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:15:02.069Z,1744132502.069 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:15:02.173Z,1744132502.173 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:15:06.734Z,1744132506.734 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.003594
CHAN A1 (24V): 0.238788
CHAN A2 (12V): -0.015663
CHAN A3 (5V): -0.047079
CHAN B0 (3.3V): -0.007419
CHAN B1 (3.15aV): -0.002697
CHAN B2 (3.15bV): -0.001737
CHAN B3 (GND): -0.007636
OPEN: 0.012413
Full Scale: +/- 1 mA
2025-04-08T17:15:37.485Z,1744132537.485 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:15:37.837Z,1744132537.837 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:15:42.279Z,1744132542.279 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.000915
CHAN A1 (24V): 0.009184
CHAN A2 (12V): -0.015769
CHAN A3 (5V): -0.045116
CHAN B0 (3.3V): -0.006496
CHAN B1 (3.15aV): -0.003550
CHAN B2 (3.15bV): -0.002465
CHAN B3 (GND): -0.006804
OPEN: 0.012431
Full Scale: +/- 1 mA
2025-04-08T17:16:09.245Z,1744132569.245 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:16:09.357Z,1744132569.357 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:16:13.802Z,1744132573.802 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.000874
CHAN A1 (24V): 0.009874
CHAN A2 (12V): -0.019719
CHAN A3 (5V): -0.035360
CHAN B0 (3.3V): -0.006872
CHAN B1 (3.15aV): -0.003265
CHAN B2 (3.15bV): -0.000529
CHAN B3 (GND): -0.005530
OPEN: 0.012088
Full Scale: +/- 1 mA
2025-04-08T17:16:41.829Z,1744132601.829 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:16:42.069Z,1744132602.069 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:16:46.506Z,1744132606.506 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.000135
CHAN A1 (24V): 0.010482
CHAN A2 (12V): -0.022776
CHAN A3 (5V): -0.032915
CHAN B0 (3.3V): -0.007587
CHAN B1 (3.15aV): -0.004050
CHAN B2 (3.15bV): -0.001376
CHAN B3 (GND): -0.005535
OPEN: 0.012180
Full Scale: +/- 1 mA
2025-04-08T17:17:42.805Z,1744132662.805 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:17:43.078Z,1744132663.078 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:17:47.545Z,1744132667.545 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.005170
CHAN A1 (24V): 0.007855
CHAN A2 (12V): -0.019044
CHAN A3 (5V): -0.044429
CHAN B0 (3.3V): -0.009029
CHAN B1 (3.15aV): -0.003468
CHAN B2 (3.15bV): -0.002721
CHAN B3 (GND): -0.005107
OPEN: 0.012071
Full Scale: +/- 1 mA
2025-04-08T17:18:28.145Z,1744132708.145 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:18:28.394Z,1744132708.394 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:18:32.801Z,1744132712.801 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.004882
CHAN A1 (24V): 0.012330
CHAN A2 (12V): -0.012229
CHAN A3 (5V): -0.043915
CHAN B0 (3.3V): -0.007564
CHAN B1 (3.15aV): -0.003489
CHAN B2 (3.15bV): -0.002086
CHAN B3 (GND): -0.006971
OPEN: 0.012342
Full Scale: +/- 1 mA
2025-04-08T17:19:17.742Z,1744132757.742 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:19:18.025Z,1744132758.025 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:19:22.518Z,1744132762.518 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.001574
CHAN A1 (24V): 0.011494
CHAN A2 (12V): -0.015393
CHAN A3 (5V): -0.038554
CHAN B0 (3.3V): -0.008137
CHAN B1 (3.15aV): -0.002918
CHAN B2 (3.15bV): -0.003148
CHAN B3 (GND): -0.005865
OPEN: 0.012266
Full Scale: +/- 1 mA
2025-04-08T17:19:50.355Z,1744132790.355 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:19:50.355Z,1744132790.355 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:19:50.355Z,1744132790.355 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:19:50.355Z,1744132790.355 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:19:50.742Z,1744132790.742 [Default:CheckIn:D] Stopped
2025-04-08T17:19:50.742Z,1744132790.742 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:19:51.162Z,1744132791.162 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  9.269936 min 
2025-04-08T17:19:51.162Z,1744132791.162 [Default:CheckIn:E] Stopped
2025-04-08T17:19:51.162Z,1744132791.162 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:19:51.162Z,1744132791.162 [Default:CheckIn] Stopped
2025-04-08T17:19:51.162Z,1744132791.162 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:19:51.163Z,1744132791.163 [Default:CheckIn](INFO): Running loop #2
2025-04-08T17:19:51.163Z,1744132791.163 [Default:CheckIn] Running Loop=2
2025-04-08T17:19:51.163Z,1744132791.163 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:19:51.163Z,1744132791.163 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:19:53.171Z,1744132793.171 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171928.00,A,3648.16660,N,12147.28178,W,0.467,12.41,080425,,,D*4E
2025-04-08T17:19:53.175Z,1744132793.175 [NAL9602](INFO): GPS fix at 20250408T171928: (36.802777, -121.788030)
2025-04-08T17:19:53.193Z,1744132793.193 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:19:53.193Z,1744132793.193 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:20:03.332Z,1744132803.332 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20250408T170617/Courier0007.lzma
2025-04-08T17:20:04.334Z,1744132804.334 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0007.lzma.bak
2025-04-08T17:20:04.334Z,1744132804.334 [DataOverHttps](INFO): SBD MOMSN=24576581
2025-04-08T17:20:20.765Z,1744132820.765 [DataOverHttps](INFO): Sending 790 bytes from file Logs/20250408T170617/Express0008.lzma
2025-04-08T17:20:21.766Z,1744132821.766 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0008.lzma.bak
2025-04-08T17:20:21.766Z,1744132821.766 [DataOverHttps](INFO): SBD MOMSN=24576622
2025-04-08T17:20:23.497Z,1744132823.497 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:20:23.497Z,1744132823.497 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:20:23.497Z,1744132823.497 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:20:23.875Z,1744132823.875 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-04-08T17:20:23.948Z,1744132823.948 [NAL9602](ERROR): received: 
+CSQ:1

OK
2025-04-08T17:20:59.677Z,1744132859.677 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T17:20:59.965Z,1744132859.965 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T17:21:04.330Z,1744132864.330 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.005871
CHAN A1 (24V): 0.012290
CHAN A2 (12V): -0.012692
CHAN A3 (5V): -0.078631
CHAN B0 (3.3V): -0.008491
CHAN B1 (3.15aV): -0.003192
CHAN B2 (3.15bV): -0.002244
CHAN B3 (GND): -0.006186
OPEN: 0.012312
Full Scale: +/- 1 mA
2025-04-08T17:21:31.400Z,1744132891.400 [CBIT](INFO): Clearing failed state for component DropWeight
2025-04-08T17:21:31.400Z,1744132891.400 [DropWeight] No Fault, FailCount= 1
2025-04-08T17:24:55.380Z,1744133095.380 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-08T17:25:24.085Z,1744133124.085 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:25:24.085Z,1744133124.085 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:25:24.085Z,1744133124.085 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:25:24.085Z,1744133124.085 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:25:24.472Z,1744133124.472 [Default:CheckIn:D] Stopped
2025-04-08T17:25:24.472Z,1744133124.472 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:25:24.874Z,1744133124.874 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  14.832114 min 
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn:E] Stopped
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn] Stopped
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn](INFO): Running loop #3
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn] Running Loop=3
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:25:24.875Z,1744133124.875 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:25:26.884Z,1744133126.884 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172502.00,A,3648.16725,N,12147.28394,W,0.136,12.41,080425,,,D*48
2025-04-08T17:25:26.886Z,1744133126.886 [NAL9602](INFO): GPS fix at 20250408T172502: (36.802788, -121.788066)
2025-04-08T17:25:26.897Z,1744133126.897 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:25:26.897Z,1744133126.897 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:25:35.083Z,1744133135.083 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T170617/Courier0010.lzma
2025-04-08T17:25:36.086Z,1744133136.086 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0010.lzma.bak
2025-04-08T17:25:36.086Z,1744133136.086 [DataOverHttps](INFO): SBD MOMSN=24576661
2025-04-08T17:25:52.488Z,1744133152.488 [DataOverHttps](INFO): Sending 427 bytes from file Logs/20250408T170617/Express0011.lzma
2025-04-08T17:25:53.490Z,1744133153.490 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0011.lzma.bak
2025-04-08T17:25:53.490Z,1744133153.490 [DataOverHttps](INFO): SBD MOMSN=24576665
2025-04-08T17:25:55.172Z,1744133155.172 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:25:55.172Z,1744133155.172 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:25:55.172Z,1744133155.172 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:25:59.256Z,1744133159.256 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-08T17:29:38.693Z,1744133378.693 [DVL_micro](ERROR): only read 3 of 4 data items for bottom velocity. Device response is::BI,+00010000.00,+00000000.00,0001.20,000.00
2025-04-08T17:29:38.693Z,1744133378.693 [DVL_micro](ERROR): Failed to parse:
:BI,+00010000.00,+00000000.00,0001.20,000.00
2025-04-08T17:29:39.826Z,1744133379.826 [DVL_micro](ERROR): Failed to parse:
:SA,-08.35,-23.74,249.2
2025-04-08T17:30:55.829Z,1744133455.829 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:30:55.829Z,1744133455.829 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:30:55.829Z,1744133455.829 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:30:55.829Z,1744133455.829 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:30:56.244Z,1744133456.244 [Default:CheckIn:D] Stopped
2025-04-08T17:30:56.244Z,1744133456.244 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:30:56.622Z,1744133456.622 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  20.361237 min 
2025-04-08T17:30:56.622Z,1744133456.622 [Default:CheckIn:E] Stopped
2025-04-08T17:30:56.622Z,1744133456.622 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:30:56.622Z,1744133456.622 [Default:CheckIn] Stopped
2025-04-08T17:30:56.622Z,1744133456.622 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:30:56.622Z,1744133456.622 [Default:CheckIn](INFO): Running loop #4
2025-04-08T17:30:56.623Z,1744133456.623 [Default:CheckIn] Running Loop=4
2025-04-08T17:30:56.623Z,1744133456.623 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:30:56.623Z,1744133456.623 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:30:58.625Z,1744133458.625 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173034.00,A,3648.16282,N,12147.28116,W,0.233,244.95,080425,,,D*77
2025-04-08T17:30:58.627Z,1744133458.627 [NAL9602](INFO): GPS fix at 20250408T173034: (36.802714, -121.788019)
2025-04-08T17:30:58.678Z,1744133458.678 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:30:58.678Z,1744133458.678 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:31:05.927Z,1744133465.927 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T170617/Courier0013.lzma
2025-04-08T17:31:06.930Z,1744133466.930 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0013.lzma.bak
2025-04-08T17:31:06.931Z,1744133466.931 [DataOverHttps](INFO): SBD MOMSN=24576681
2025-04-08T17:31:23.252Z,1744133483.252 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250408T170617/Express0014.lzma
2025-04-08T17:31:24.254Z,1744133484.254 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0014.lzma.bak
2025-04-08T17:31:24.254Z,1744133484.254 [DataOverHttps](INFO): SBD MOMSN=24576725
2025-04-08T17:31:25.819Z,1744133485.819 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:31:25.819Z,1744133485.819 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:31:25.819Z,1744133485.819 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:31:29.434Z,1744133489.434 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-04-08T17:31:29.508Z,1744133489.508 [NAL9602](ERROR): received: 
+CSQ:0

OK
2025-04-08T17:36:01.390Z,1744133761.390 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-08T17:36:26.438Z,1744133786.438 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:36:26.438Z,1744133786.438 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:36:26.438Z,1744133786.438 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:36:26.438Z,1744133786.438 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:36:26.981Z,1744133786.981 [Default:CheckIn:D] Stopped
2025-04-08T17:36:26.981Z,1744133786.981 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:36:27.259Z,1744133787.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  25.873926 min 
2025-04-08T17:36:27.259Z,1744133787.259 [Default:CheckIn:E] Stopped
2025-04-08T17:36:27.260Z,1744133787.260 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:36:27.260Z,1744133787.260 [Default:CheckIn] Stopped
2025-04-08T17:36:27.260Z,1744133787.260 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:36:27.260Z,1744133787.260 [Default:CheckIn](INFO): Running loop #5
2025-04-08T17:36:27.260Z,1744133787.260 [Default:CheckIn] Running Loop=5
2025-04-08T17:36:27.260Z,1744133787.260 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:36:27.260Z,1744133787.260 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:36:29.254Z,1744133789.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173604.00,A,3648.16582,N,12147.28079,W,0.058,244.95,080425,,,D*72
2025-04-08T17:36:29.256Z,1744133789.256 [NAL9602](INFO): GPS fix at 20250408T173604: (36.802764, -121.788013)
2025-04-08T17:36:29.267Z,1744133789.267 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:36:29.267Z,1744133789.267 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:36:37.467Z,1744133797.467 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T170617/Courier0016.lzma
2025-04-08T17:36:38.471Z,1744133798.471 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0016.lzma.bak
2025-04-08T17:36:38.471Z,1744133798.471 [DataOverHttps](INFO): SBD MOMSN=24576731
2025-04-08T17:36:54.800Z,1744133814.800 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20250408T170617/Express0017.lzma
2025-04-08T17:36:55.802Z,1744133815.802 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0017.lzma.bak
2025-04-08T17:36:55.802Z,1744133815.802 [DataOverHttps](INFO): SBD MOMSN=24576737
2025-04-08T17:36:57.991Z,1744133817.991 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:36:57.991Z,1744133817.991 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:36:57.991Z,1744133817.991 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:37:01.187Z,1744133821.187 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-08T17:38:46.646Z,1744133926.646 [DVL_micro](ERROR): Failed to parse:
:SA,-08.43,-23.83,225.7
2025-04-08T17:41:58.551Z,1744134118.551 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:41:58.551Z,1744134118.551 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:41:58.551Z,1744134118.551 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:41:58.552Z,1744134118.552 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:41:58.950Z,1744134118.950 [Default:CheckIn:D] Stopped
2025-04-08T17:41:58.950Z,1744134118.950 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:41:59.358Z,1744134119.358 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  31.406748 min 
2025-04-08T17:41:59.358Z,1744134119.358 [Default:CheckIn:E] Stopped
2025-04-08T17:41:59.358Z,1744134119.358 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:41:59.358Z,1744134119.358 [Default:CheckIn] Stopped
2025-04-08T17:41:59.358Z,1744134119.358 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:41:59.359Z,1744134119.359 [Default:CheckIn](INFO): Running loop #6
2025-04-08T17:41:59.359Z,1744134119.359 [Default:CheckIn] Running Loop=6
2025-04-08T17:41:59.359Z,1744134119.359 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:41:59.359Z,1744134119.359 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:42:01.375Z,1744134121.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174136.00,A,3648.16502,N,12147.28283,W,0.680,6.51,080425,,,D*73
2025-04-08T17:42:01.378Z,1744134121.378 [NAL9602](INFO): GPS fix at 20250408T174136: (36.802750, -121.788047)
2025-04-08T17:42:01.388Z,1744134121.388 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:42:01.388Z,1744134121.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:42:08.707Z,1744134128.707 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250408T170617/Courier0019.lzma
2025-04-08T17:42:09.710Z,1744134129.710 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0019.lzma.bak
2025-04-08T17:42:09.710Z,1744134129.710 [DataOverHttps](INFO): SBD MOMSN=24576762
2025-04-08T17:42:26.172Z,1744134146.172 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250408T170617/Express0020.lzma
2025-04-08T17:42:27.174Z,1744134147.174 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0020.lzma.bak
2025-04-08T17:42:27.174Z,1744134147.174 [DataOverHttps](INFO): SBD MOMSN=24576802
2025-04-08T17:42:28.980Z,1744134148.980 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:42:28.980Z,1744134148.980 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:42:28.980Z,1744134148.980 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:42:32.220Z,1744134152.220 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-04-08T17:42:32.304Z,1744134152.304 [NAL9602](ERROR): received: 
+CSQ:0

OK
2025-04-08T17:43:28.768Z,1744134208.768 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+17.9,0000.0,1489.0,000
2025-04-08T17:44:47.145Z,1744134287.145 [DVL_micro](ERROR): Failed to parse:
:SA,-08.37,-23.77,232.9
2025-04-08T17:46:13.602Z,1744134373.602 [NAL9602](INFO): SBD MO Status=2, MOMSN=19213, MT Status=2, MTMSN=0
2025-04-08T17:46:13.602Z,1744134373.602 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-08T17:47:13.807Z,1744134433.807 [NAL9602](INFO): SBD MO Status=2, MOMSN=19213, MT Status=2, MTMSN=0
2025-04-08T17:47:13.807Z,1744134433.807 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-08T17:47:14.206Z,1744134434.206 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-08T17:47:29.577Z,1744134449.577 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:47:29.577Z,1744134449.577 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:47:29.577Z,1744134449.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:47:29.578Z,1744134449.578 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:47:29.981Z,1744134449.981 [Default:CheckIn:D] Stopped
2025-04-08T17:47:29.981Z,1744134449.981 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:47:30.398Z,1744134450.398 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  36.923930 min 
2025-04-08T17:47:30.398Z,1744134450.398 [Default:CheckIn:E] Stopped
2025-04-08T17:47:30.398Z,1744134450.398 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:47:30.398Z,1744134450.398 [Default:CheckIn] Stopped
2025-04-08T17:47:30.398Z,1744134450.398 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:47:30.399Z,1744134450.399 [Default:CheckIn](INFO): Running loop #7
2025-04-08T17:47:30.399Z,1744134450.399 [Default:CheckIn] Running Loop=7
2025-04-08T17:47:30.399Z,1744134450.399 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:47:30.399Z,1744134450.399 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:47:32.394Z,1744134452.394 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174707.00,A,3648.16645,N,12147.27963,W,0.058,6.51,080425,,,A*7B
2025-04-08T17:47:32.396Z,1744134452.396 [NAL9602](INFO): GPS fix at 20250408T174707: (36.802774, -121.787994)
2025-04-08T17:47:32.406Z,1744134452.406 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:47:32.406Z,1744134452.406 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:47:37.717Z,1744134457.717 [DAT](INFO): DAT read: user:6>Rx Time:17:47:37.0286

2025-04-08T17:47:37.717Z,1744134457.717 [DAT](INFO): Rx dataTimestamp_ set to:1744134457.717089
2025-04-08T17:47:38.221Z,1744134458.221 [DAT](INFO): DAT read: 

2025-04-08T17:47:38.222Z,1744134458.222 [DAT](INFO): DAT read: $Packet for address 3

2025-04-08T17:47:38.223Z,1744134458.223 [DAT](INFO): received a packet notification
2025-04-08T17:47:39.831Z,1744134459.831 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T170617/Courier0022.lzma
2025-04-08T17:47:40.834Z,1744134460.834 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0022.lzma.bak
2025-04-08T17:47:40.834Z,1744134460.834 [DataOverHttps](INFO): SBD MOMSN=24576823
2025-04-08T17:47:51.839Z,1744134471.839 [DAT](INFO): DAT read: Rx Time:17:47:51.1289

2025-04-08T17:47:51.840Z,1744134471.840 [DAT](INFO): Rx dataTimestamp_ set to:1744134471.839387
2025-04-08T17:47:52.345Z,1744134472.345 [DAT](INFO): DAT read: range request

2025-04-08T17:47:52.345Z,1744134472.345 [DAT](INFO): received a range request message
2025-04-08T17:47:52.345Z,1744134472.345 [DAT](INFO): DAT read: Tx time:17:47:52.7317

2025-04-08T17:47:52.346Z,1744134472.346 [DAT](INFO): Ping request sent.
2025-04-08T17:47:52.346Z,1744134472.346 [DAT](INFO): transmitted an acoustic signal
2025-04-08T17:47:52.346Z,1744134472.346 [DAT](INFO): publishing transmit ping time
2025-04-08T17:47:52.346Z,1744134472.346 [DAT](INFO): publishing range request flag
2025-04-08T17:47:52.347Z,1744134472.347 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001304
2025-04-08T17:47:52.597Z,1744134472.597 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251052
2025-04-08T17:47:52.849Z,1744134472.849 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503013
2025-04-08T17:47:53.101Z,1744134473.101 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755477
2025-04-08T17:47:53.353Z,1744134473.353 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007181
2025-04-08T17:47:53.605Z,1744134473.605 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258969
2025-04-08T17:47:53.857Z,1744134473.857 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510937
2025-04-08T17:47:54.110Z,1744134474.110 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763844
2025-04-08T17:47:54.361Z,1744134474.361 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014920
2025-04-08T17:47:54.613Z,1744134474.613 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266892
2025-04-08T17:47:54.865Z,1744134474.865 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518917
2025-04-08T17:47:55.117Z,1744134475.117 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771268
2025-04-08T17:47:55.369Z,1744134475.369 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022915
2025-04-08T17:47:55.621Z,1744134475.621 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275036
2025-04-08T17:47:55.893Z,1744134475.893 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.547015
2025-04-08T17:47:56.149Z,1744134476.149 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.802818
2025-04-08T17:47:56.401Z,1744134476.401 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.054921
2025-04-08T17:47:56.653Z,1744134476.653 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.306934
2025-04-08T17:47:56.905Z,1744134476.905 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.558953
2025-04-08T17:47:57.157Z,1744134477.157 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.810866
2025-04-08T17:47:57.409Z,1744134477.409 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.062852
2025-04-08T17:47:57.661Z,1744134477.661 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.315025
2025-04-08T17:47:57.913Z,1744134477.913 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.567368
2025-04-08T17:47:58.165Z,1744134478.165 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.819084
2025-04-08T17:47:58.417Z,1744134478.417 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.071028
2025-04-08T17:47:58.508Z,1744134478.508 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20250408T170617/Express0023.lzma
2025-04-08T17:47:58.669Z,1744134478.669 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.322834
2025-04-08T17:47:58.921Z,1744134478.921 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.575289
2025-04-08T17:47:59.173Z,1744134479.173 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.826918
2025-04-08T17:47:59.425Z,1744134479.425 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.079113
2025-04-08T17:47:59.510Z,1744134479.510 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0023.lzma.bak
2025-04-08T17:47:59.510Z,1744134479.510 [DataOverHttps](INFO): SBD MOMSN=24576826
2025-04-08T17:47:59.677Z,1744134479.677 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.331044
2025-04-08T17:47:59.929Z,1744134479.929 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.582849
2025-04-08T17:48:00.181Z,1744134480.181 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.835112
2025-04-08T17:48:00.433Z,1744134480.433 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.086926
2025-04-08T17:48:00.685Z,1744134480.685 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.338992
2025-04-08T17:48:00.937Z,1744134480.937 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.591537
2025-04-08T17:48:01.191Z,1744134481.191 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.845446
2025-04-08T17:48:01.199Z,1744134481.199 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:48:01.199Z,1744134481.199 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:48:01.199Z,1744134481.199 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:48:01.441Z,1744134481.441 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.094839
2025-04-08T17:48:01.693Z,1744134481.693 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.347229
2025-04-08T17:48:01.945Z,1744134481.945 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.599303
2025-04-08T17:48:02.197Z,1744134482.197 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.850845
2025-04-08T17:48:04.421Z,1744134484.421 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-08T17:51:32.867Z,1744134692.867 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2025-04-08T17:51:32.867Z,1744134692.867 [DropWeight] Hardware Fault, FailCount= 1
2025-04-08T17:51:32.867Z,1744134692.867 [DropWeight](ERROR): Hardware Fault
2025-04-08T17:51:32.925Z,1744134692.925 [CBIT](INFO): Critical error at 20250408T175132
2025-04-08T17:51:32.927Z,1744134692.927 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-04-08T17:51:32.927Z,1744134692.927 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-04-08T17:51:33.300Z,1744134693.300 [CBIT](INFO): Critical error at 20250408T175132
2025-04-08T17:53:01.774Z,1744134781.774 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:53:01.774Z,1744134781.774 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:53:01.774Z,1744134781.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:53:01.774Z,1744134781.774 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:53:02.180Z,1744134782.180 [Default:CheckIn:D] Stopped
2025-04-08T17:53:02.180Z,1744134782.180 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:53:02.596Z,1744134782.596 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  42.460571 min 
2025-04-08T17:53:02.596Z,1744134782.596 [Default:CheckIn:E] Stopped
2025-04-08T17:53:02.596Z,1744134782.596 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:53:02.596Z,1744134782.596 [Default:CheckIn] Stopped
2025-04-08T17:53:02.597Z,1744134782.597 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:53:02.597Z,1744134782.597 [Default:CheckIn](INFO): Running loop #8
2025-04-08T17:53:02.597Z,1744134782.597 [Default:CheckIn] Running Loop=8
2025-04-08T17:53:02.597Z,1744134782.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:53:02.597Z,1744134782.597 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:53:04.589Z,1744134784.589 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175240.00,A,3648.16547,N,12147.28077,W,0.078,6.51,080425,,,D*79
2025-04-08T17:53:04.591Z,1744134784.591 [NAL9602](INFO): GPS fix at 20250408T175240: (36.802758, -121.788013)
2025-04-08T17:53:04.602Z,1744134784.602 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:53:04.602Z,1744134784.602 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:53:12.732Z,1744134792.732 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250408T170617/Courier0025.lzma
2025-04-08T17:53:13.734Z,1744134793.734 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0025.lzma.bak
2025-04-08T17:53:13.734Z,1744134793.734 [DataOverHttps](INFO): SBD MOMSN=24576882
2025-04-08T17:53:30.131Z,1744134810.131 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20250408T170617/Express0026.lzma
2025-04-08T17:53:31.131Z,1744134811.131 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0026.lzma.bak
2025-04-08T17:53:31.131Z,1744134811.131 [DataOverHttps](INFO): SBD MOMSN=24576887
2025-04-08T17:53:32.877Z,1744134812.877 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:53:32.877Z,1744134812.877 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:53:32.877Z,1744134812.877 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:58:03.145Z,1744135083.145 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,0000.20,000.00
2025-04-08T17:58:07.181Z,1744135087.181 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-08T17:58:33.445Z,1744135113.445 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T17:58:33.445Z,1744135113.445 [Default:CheckIn:C.Wait] Stopped
2025-04-08T17:58:33.445Z,1744135113.445 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T17:58:33.445Z,1744135113.445 [Default:CheckIn:D] Running Loop=1
2025-04-08T17:58:33.855Z,1744135113.855 [Default:CheckIn:D] Stopped
2025-04-08T17:58:33.855Z,1744135113.855 [Default:CheckIn:E] Running Loop=1
2025-04-08T17:58:34.258Z,1744135114.258 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  47.988497 min 
2025-04-08T17:58:34.258Z,1744135114.258 [Default:CheckIn:E] Stopped
2025-04-08T17:58:34.258Z,1744135114.258 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T17:58:34.258Z,1744135114.258 [Default:CheckIn] Stopped
2025-04-08T17:58:34.259Z,1744135114.259 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T17:58:34.259Z,1744135114.259 [Default:CheckIn](INFO): Running loop #9
2025-04-08T17:58:34.259Z,1744135114.259 [Default:CheckIn] Running Loop=9
2025-04-08T17:58:34.259Z,1744135114.259 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T17:58:34.259Z,1744135114.259 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T17:58:36.270Z,1744135116.270 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175811.00,A,3648.16534,N,12147.27963,W,0.019,6.51,080425,,,D*77
2025-04-08T17:58:36.274Z,1744135116.274 [NAL9602](INFO): GPS fix at 20250408T175811: (36.802756, -121.787994)
2025-04-08T17:58:36.306Z,1744135116.306 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T17:58:36.306Z,1744135116.306 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T17:58:44.067Z,1744135124.067 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T170617/Courier0028.lzma
2025-04-08T17:58:45.070Z,1744135125.070 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0028.lzma.bak
2025-04-08T17:58:45.070Z,1744135125.070 [DataOverHttps](INFO): SBD MOMSN=24576904
2025-04-08T17:59:03.080Z,1744135143.080 [DataOverHttps](INFO): Sending 273 bytes from file Logs/20250408T170617/Express0029.lzma
2025-04-08T17:59:04.082Z,1744135144.082 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0029.lzma.bak
2025-04-08T17:59:04.082Z,1744135144.082 [DataOverHttps](INFO): SBD MOMSN=24576907
2025-04-08T17:59:05.797Z,1744135145.797 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T17:59:05.797Z,1744135145.797 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T17:59:05.797Z,1744135145.797 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T17:59:09.402Z,1744135149.402 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-08T18:04:06.353Z,1744135446.353 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T18:04:06.353Z,1744135446.353 [Default:CheckIn:C.Wait] Stopped
2025-04-08T18:04:06.353Z,1744135446.353 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T18:04:06.353Z,1744135446.353 [Default:CheckIn:D] Running Loop=1
2025-04-08T18:04:06.741Z,1744135446.741 [Default:CheckIn:D] Stopped
2025-04-08T18:04:06.742Z,1744135446.742 [Default:CheckIn:E] Running Loop=1
2025-04-08T18:04:07.154Z,1744135447.154 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  53.536601 min 
2025-04-08T18:04:07.154Z,1744135447.154 [Default:CheckIn:E] Stopped
2025-04-08T18:04:07.155Z,1744135447.155 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T18:04:07.155Z,1744135447.155 [Default:CheckIn] Stopped
2025-04-08T18:04:07.155Z,1744135447.155 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T18:04:07.155Z,1744135447.155 [Default:CheckIn](INFO): Running loop #10
2025-04-08T18:04:07.155Z,1744135447.155 [Default:CheckIn] Running Loop=10
2025-04-08T18:04:07.155Z,1744135447.155 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T18:04:07.155Z,1744135447.155 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T18:04:09.173Z,1744135449.173 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180344.00,A,3648.16520,N,12147.28158,W,0.058,233.41,080425,,,D*7C
2025-04-08T18:04:09.175Z,1744135449.175 [NAL9602](INFO): GPS fix at 20250408T180344: (36.802753, -121.788026)
2025-04-08T18:04:09.185Z,1744135449.185 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T18:04:09.185Z,1744135449.185 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T18:04:16.887Z,1744135456.887 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250408T170617/Courier0031.lzma
2025-04-08T18:04:17.887Z,1744135457.887 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0031.lzma.bak
2025-04-08T18:04:17.887Z,1744135457.887 [DataOverHttps](INFO): SBD MOMSN=24577042
2025-04-08T18:04:34.268Z,1744135474.268 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20250408T170617/Express0032.lzma
2025-04-08T18:04:35.270Z,1744135475.270 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0032.lzma.bak
2025-04-08T18:04:35.270Z,1744135475.270 [DataOverHttps](INFO): SBD MOMSN=24577048
2025-04-08T18:04:37.056Z,1744135477.056 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T18:04:37.056Z,1744135477.056 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T18:04:37.056Z,1744135477.056 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T18:04:39.870Z,1744135479.870 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-04-08T18:04:39.948Z,1744135479.948 [NAL9602](ERROR): received: 
+CSQ:0

OK213, 2, 0, 0, 0

OK
2025-04-08T18:06:33.060Z,1744135593.060 [CBIT](INFO): Clearing failed state for component DropWeight
2025-04-08T18:06:33.060Z,1744135593.060 [DropWeight] No Fault, FailCount= 1
2025-04-08T18:09:11.367Z,1744135751.367 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-08T18:09:37.649Z,1744135777.649 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T18:09:37.649Z,1744135777.649 [Default:CheckIn:C.Wait] Stopped
2025-04-08T18:09:37.649Z,1744135777.649 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T18:09:37.649Z,1744135777.649 [Default:CheckIn:D] Running Loop=1
2025-04-08T18:09:38.039Z,1744135778.039 [Default:CheckIn:D] Stopped
2025-04-08T18:09:38.040Z,1744135778.040 [Default:CheckIn:E] Running Loop=1
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  59.058236 min 
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn:E] Stopped
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn] Stopped
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn](INFO): Running loop #11
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn] Running Loop=11
2025-04-08T18:09:38.439Z,1744135778.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T18:09:38.456Z,1744135778.456 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T18:09:40.450Z,1744135780.450 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180915.00,A,3648.16244,N,12147.28159,W,0.097,233.41,080425,,,D*75
2025-04-08T18:09:40.452Z,1744135780.452 [NAL9602](INFO): GPS fix at 20250408T180915: (36.802707, -121.788027)
2025-04-08T18:09:40.463Z,1744135780.463 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T18:09:40.463Z,1744135780.463 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T18:09:48.292Z,1744135788.292 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T170617/Courier0034.lzma
2025-04-08T18:09:49.294Z,1744135789.294 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0034.lzma.bak
2025-04-08T18:09:49.294Z,1744135789.294 [DataOverHttps](INFO): SBD MOMSN=24577091
2025-04-08T18:10:06.060Z,1744135806.060 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20250408T170617/Express0035.lzma
2025-04-08T18:10:07.062Z,1744135807.062 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0035.lzma.bak
2025-04-08T18:10:07.062Z,1744135807.062 [DataOverHttps](INFO): SBD MOMSN=24577094
2025-04-08T18:10:08.778Z,1744135808.778 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T18:10:08.778Z,1744135808.778 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T18:10:08.778Z,1744135808.778 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T18:10:12.415Z,1744135812.415 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-08T18:15:09.377Z,1744136109.377 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T18:15:09.377Z,1744136109.377 [Default:CheckIn:C.Wait] Stopped
2025-04-08T18:15:09.377Z,1744136109.377 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T18:15:09.377Z,1744136109.377 [Default:CheckIn:D] Running Loop=1
2025-04-08T18:15:09.763Z,1744136109.763 [Default:CheckIn:D] Stopped
2025-04-08T18:15:09.763Z,1744136109.763 [Default:CheckIn:E] Running Loop=1
2025-04-08T18:15:10.158Z,1744136110.158 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  64.586955 min 
2025-04-08T18:15:10.158Z,1744136110.158 [Default:CheckIn:E] Stopped
2025-04-08T18:15:10.158Z,1744136110.158 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T18:15:10.158Z,1744136110.158 [Default:CheckIn] Stopped
2025-04-08T18:15:10.158Z,1744136110.158 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T18:15:10.158Z,1744136110.158 [Default:CheckIn](INFO): Running loop #12
2025-04-08T18:15:10.159Z,1744136110.159 [Default:CheckIn] Running Loop=12
2025-04-08T18:15:10.159Z,1744136110.159 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T18:15:10.159Z,1744136110.159 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T18:15:12.166Z,1744136112.166 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181447.00,A,3648.16491,N,12147.28562,W,0.583,159.78,080425,,,D*79
2025-04-08T18:15:12.169Z,1744136112.169 [NAL9602](INFO): GPS fix at 20250408T181447: (36.802748, -121.788094)
2025-04-08T18:15:12.203Z,1744136112.203 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T18:15:12.203Z,1744136112.203 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T18:15:20.515Z,1744136120.515 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250408T170617/Courier0037.lzma
2025-04-08T18:15:21.518Z,1744136121.518 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0037.lzma.bak
2025-04-08T18:15:21.518Z,1744136121.518 [DataOverHttps](INFO): SBD MOMSN=24577236
2025-04-08T18:15:38.662Z,1744136138.662 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250408T170617/Express0038.lzma
2025-04-08T18:15:38.918Z,1744136138.918 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0038.lzma.bak
2025-04-08T18:15:38.918Z,1744136138.918 [DataOverHttps](INFO): SBD MOMSN=24577241
2025-04-08T18:15:40.859Z,1744136140.859 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T18:15:40.859Z,1744136140.859 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T18:15:40.859Z,1744136140.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T18:15:42.875Z,1744136142.875 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-04-08T18:15:42.956Z,1744136142.956 [NAL9602](ERROR): received: 
+CSQ:0

OK213, 2, 0, 0, 0

OK
2025-04-08T18:19:23.409Z,1744136363.409 [CommandExec](IMPORTANT): got command gfscan
2025-04-08T18:19:23.495Z,1744136363.495 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-08T18:19:27.939Z,1744136367.939 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.002941
CHAN A1 (24V): 0.007560
CHAN A2 (12V): -0.017452
CHAN A3 (5V): -0.042905
CHAN B0 (3.3V): -0.007061
CHAN B1 (3.15aV): -0.003551
CHAN B2 (3.15bV): -0.001899
CHAN B3 (GND): -0.007142
OPEN: 0.012197
Full Scale: +/- 1 mA
2025-04-08T18:20:09.113Z,1744136409.113 [NAL9602](INFO): SBD MO Status=2, MOMSN=19213, MT Status=2, MTMSN=0
2025-04-08T18:20:09.114Z,1744136409.114 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-08T18:20:13.966Z,1744136413.966 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-08T18:20:39.417Z,1744136439.417 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-04-08T18:20:39.418Z,1744136439.418 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 6.
2025-04-08T18:20:39.437Z,1744136439.437 [BPC1](INFO): Received data from all battery sticks.
2025-04-08T18:20:41.449Z,1744136441.449 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-08T18:20:41.449Z,1744136441.449 [Default:CheckIn:C.Wait] Stopped
2025-04-08T18:20:41.450Z,1744136441.450 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-08T18:20:41.450Z,1744136441.450 [Default:CheckIn:D] Running Loop=1
2025-04-08T18:20:41.843Z,1744136441.843 [Default:CheckIn:D] Stopped
2025-04-08T18:20:41.843Z,1744136441.843 [Default:CheckIn:E] Running Loop=1
2025-04-08T18:20:42.262Z,1744136442.262 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  70.121623 min 
2025-04-08T18:20:42.262Z,1744136442.262 [Default:CheckIn:E] Stopped
2025-04-08T18:20:42.263Z,1744136442.263 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-08T18:20:42.263Z,1744136442.263 [Default:CheckIn] Stopped
2025-04-08T18:20:42.263Z,1744136442.263 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-08T18:20:42.263Z,1744136442.263 [Default:CheckIn](INFO): Running loop #13
2025-04-08T18:20:42.263Z,1744136442.263 [Default:CheckIn] Running Loop=13
2025-04-08T18:20:42.263Z,1744136442.263 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-08T18:20:42.263Z,1744136442.263 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-08T18:20:44.267Z,1744136444.267 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182019.00,A,3648.16342,N,12147.28557,W,0.233,178.40,080425,,,D*7E
2025-04-08T18:20:44.269Z,1744136444.269 [NAL9602](INFO): GPS fix at 20250408T182019: (36.802724, -121.788093)
2025-04-08T18:20:44.308Z,1744136444.308 [Default:CheckIn:Read_GPS] Stopped
2025-04-08T18:20:44.308Z,1744136444.308 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-08T18:20:52.372Z,1744136452.372 [DataOverHttps](INFO): Sending 88 bytes from file Logs/20250408T170617/Courier0040.lzma
2025-04-08T18:20:53.374Z,1744136453.374 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Courier0040.lzma.bak
2025-04-08T18:20:53.374Z,1744136453.374 [DataOverHttps](INFO): SBD MOMSN=24577257
2025-04-08T18:21:12.128Z,1744136472.128 [DataOverHttps](INFO): Sending 422 bytes from file Logs/20250408T170617/Express0041.lzma
2025-04-08T18:21:13.130Z,1744136473.130 [DataOverHttps](INFO): Moved sent file to Logs/20250408T170617/Express0041.lzma.bak
2025-04-08T18:21:13.130Z,1744136473.130 [DataOverHttps](INFO): SBD MOMSN=24577260
2025-04-08T18:21:15.002Z,1744136475.002 [Default:CheckIn:Read_Iridium] Stopped
2025-04-08T18:21:15.002Z,1744136475.002 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-08T18:21:15.002Z,1744136475.002 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-08T18:21:16.220Z,1744136476.220 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-08T18:25:27.737Z,1744136727.737 [CommandExec](IMPORTANT): got command restart system
2025-04-08T18:25:29.836Z,1744136729.836 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-08T18:25:29.836Z,1744136729.836 [CommandExec](INFO): Uninitializing the command executive.
2025-04-08T18:25:29.836Z,1744136729.836 [CommandExec](INFO): Uninitializing the command scheduler.
2025-04-08T18:25:29.837Z,1744136729.837 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:29.916Z,1744136729.916 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2025-04-08T18:25:29.916Z,1744136729.916 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-04-08T18:25:29.916Z,1744136729.916 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:29.917Z,1744136729.917 [NavChartDb](INFO): Join timeout helper Thread ID is 1398
2025-04-08T18:25:30.224Z,1744136730.224 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-08T18:25:30.224Z,1744136730.224 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:30.242Z,1744136730.242 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-04-08T18:25:30.242Z,1744136730.242 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:30.242Z,1744136730.242 [Radio_Surface](INFO): Join timeout helper Thread ID is 1399
2025-04-08T18:25:30.528Z,1744136730.528 [Radio_Surface](INFO): Powering down
2025-04-08T18:25:30.529Z,1744136730.529 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-08T18:25:30.529Z,1744136730.529 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:30.544Z,1744136730.544 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-04-08T18:25:30.544Z,1744136730.544 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:30.544Z,1744136730.544 [Onboard](INFO): Join timeout helper Thread ID is 1400
2025-04-08T18:25:30.708Z,1744136730.708 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-04-08T18:25:33.876Z,1744136733.876 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-08T18:25:33.876Z,1744136733.876 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:33.899Z,1744136733.899 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-04-08T18:25:33.900Z,1744136733.900 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:33.908Z,1744136733.908 [DataOverHttps](INFO): Join timeout helper Thread ID is 1401
2025-04-08T18:25:34.724Z,1744136734.724 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-08T18:25:34.724Z,1744136734.724 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:34.735Z,1744136734.735 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2025-04-08T18:25:34.736Z,1744136734.736 [DAT ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:34.748Z,1744136734.748 [DAT](INFO): Join timeout helper Thread ID is 1402
2025-04-08T18:25:34.796Z,1744136734.796 [DAT](INFO): Powering down
2025-04-08T18:25:34.869Z,1744136734.869 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-08T18:25:34.869Z,1744136734.869 [DAT](INFO): Powering down
2025-04-08T18:25:34.870Z,1744136734.870 [DAT ThreadHandler](INFO): Thread cancelled.
2025-04-08T18:25:34.881Z,1744136734.