2025-06-03T18:53:26.364Z,1748976806.364 [Supervisor](DEBUG): Initializing supervisor. 2025-06-03T18:53:26.368Z,1748976806.368 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-06-03T18:53:26.369Z,1748976806.369 [SyncHandler](INFO): Protected caller Thread ID is 830 2025-06-03T18:53:26.369Z,1748976806.369 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-06-03T18:53:26.370Z,1748976806.370 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-06-03T18:53:26.370Z,1748976806.370 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 831 2025-06-03T18:53:26.375Z,1748976806.375 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-06-03T18:53:26.396Z,1748976806.396 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-06-03T18:53:26.397Z,1748976806.397 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-06-03T18:53:26.397Z,1748976806.397 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 832 2025-06-03T18:53:26.402Z,1748976806.402 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-06-03T18:53:26.403Z,1748976806.403 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-06-03T18:53:26.403Z,1748976806.403 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 833 2025-06-03T18:53:26.405Z,1748976806.405 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-06-03T18:53:26.406Z,1748976806.406 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-06-03T18:53:26.407Z,1748976806.407 [logger ThreadHandler](INFO): Protected caller Thread ID is 834 2025-06-03T18:53:26.411Z,1748976806.411 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-06-03T18:53:26.411Z,1748976806.411 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-06-03T18:53:26.416Z,1748976806.416 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-06-03T18:53:26.522Z,1748976806.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-06-03T18:53:26.524Z,1748976806.524 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-06-03T18:53:26.756Z,1748976806.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-06-03T18:53:26.757Z,1748976806.757 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-06-03T18:53:27.037Z,1748976807.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-06-03T18:53:27.039Z,1748976807.039 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-06-03T18:53:27.155Z,1748976807.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-06-03T18:53:27.157Z,1748976807.157 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-06-03T18:53:27.922Z,1748976807.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-06-03T18:53:27.923Z,1748976807.923 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-06-03T18:53:28.447Z,1748976808.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-06-03T18:53:28.447Z,1748976808.447 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-06-03T18:53:29.005Z,1748976809.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-06-03T18:53:29.005Z,1748976809.005 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-06-03T18:53:29.433Z,1748976809.433 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-06-03T18:53:29.434Z,1748976809.434 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-06-03T18:53:29.799Z,1748976809.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-06-03T18:53:29.799Z,1748976809.799 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-06-03T18:53:30.484Z,1748976810.484 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-06-03T18:53:30.485Z,1748976810.485 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-06-03T18:53:30.719Z,1748976810.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-06-03T18:53:30.721Z,1748976810.721 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-06-03T18:53:30.872Z,1748976810.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-06-03T18:53:30.874Z,1748976810.874 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-06-03T18:53:30.976Z,1748976810.976 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-06-03T18:53:30.977Z,1748976810.977 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-06-03T18:53:31.066Z,1748976811.066 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-06-03T18:53:31.263Z,1748976811.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-06-03T18:53:31.264Z,1748976811.264 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-06-03T18:53:31.523Z,1748976811.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-06-03T18:53:31.525Z,1748976811.525 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2025-06-03T18:53:31.529Z,1748976811.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2025-06-03T18:53:31.622Z,1748976811.622 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2025-06-03T18:53:31.898Z,1748976811.898 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-06-03T18:53:31.899Z,1748976811.899 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2025-06-03T18:53:31.994Z,1748976811.994 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2025-06-03T18:53:32.175Z,1748976812.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2025-06-03T18:53:32.286Z,1748976812.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2025-06-03T18:53:32.406Z,1748976812.406 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2025-06-03T18:53:32.529Z,1748976812.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2025-06-03T18:53:32.633Z,1748976812.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2025-06-03T18:53:32.805Z,1748976812.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2025-06-03T18:53:32.912Z,1748976812.912 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg 2025-06-03T18:53:33.008Z,1748976813.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2025-06-03T18:53:33.116Z,1748976813.116 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2025-06-03T18:53:33.214Z,1748976813.214 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-06-03T18:53:33.226Z,1748976813.226 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-06-03T18:53:33.456Z,1748976813.456 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-06-03T18:53:33.457Z,1748976813.457 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-06-03T18:53:33.654Z,1748976813.654 [BuoyancyServo] Loaded 2025-06-03T18:53:33.654Z,1748976813.654 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-06-03T18:53:33.678Z,1748976813.678 [ElevatorServo] Loaded 2025-06-03T18:53:33.678Z,1748976813.678 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-06-03T18:53:33.701Z,1748976813.701 [MassServo] Loaded 2025-06-03T18:53:33.702Z,1748976813.702 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-06-03T18:53:33.724Z,1748976813.724 [RudderServo] Loaded 2025-06-03T18:53:33.724Z,1748976813.724 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-06-03T18:53:33.743Z,1748976813.743 [ThrusterHE] Loaded 2025-06-03T18:53:33.743Z,1748976813.743 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-06-03T18:53:33.743Z,1748976813.743 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-06-03T18:53:33.745Z,1748976813.745 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-06-03T18:53:33.953Z,1748976813.953 [SBIT](DEBUG): Construct Startup Built In Test. 2025-06-03T18:53:33.968Z,1748976813.968 [SBIT] Loaded 2025-06-03T18:53:33.968Z,1748976813.968 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-06-03T18:53:33.971Z,1748976813.971 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-06-03T18:53:33.993Z,1748976813.993 [IBIT] Loaded 2025-06-03T18:53:33.993Z,1748976813.993 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-06-03T18:53:33.998Z,1748976813.998 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-06-03T18:53:34.195Z,1748976814.195 [CBIT] Loaded 2025-06-03T18:53:34.195Z,1748976814.195 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-06-03T18:53:34.227Z,1748976814.227 [GFScanner] Loaded 2025-06-03T18:53:34.227Z,1748976814.227 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-06-03T18:53:34.228Z,1748976814.228 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-06-03T18:53:34.228Z,1748976814.228 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-06-03T18:53:34.455Z,1748976814.455 [CTD_Seabird] Loaded 2025-06-03T18:53:34.455Z,1748976814.455 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-06-03T18:53:34.456Z,1748976814.456 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406864E0 2025-06-03T18:53:34.456Z,1748976814.456 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 922 2025-06-03T18:53:34.492Z,1748976814.492 [ESPComponent] Loaded 2025-06-03T18:53:34.492Z,1748976814.492 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-06-03T18:53:34.515Z,1748976814.515 [PAR_Licor] Loaded 2025-06-03T18:53:34.515Z,1748976814.515 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-06-03T18:53:34.561Z,1748976814.561 [WetLabsBB2FL] Loaded 2025-06-03T18:53:34.562Z,1748976814.562 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-06-03T18:53:34.563Z,1748976814.563 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0 2025-06-03T18:53:34.563Z,1748976814.563 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 923 2025-06-03T18:53:34.564Z,1748976814.564 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-06-03T18:53:34.564Z,1748976814.564 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-06-03T18:53:34.638Z,1748976814.638 [DepthRateCalculator] Loaded 2025-06-03T18:53:34.638Z,1748976814.638 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-06-03T18:53:34.643Z,1748976814.643 [PitchRateCalculator] Loaded 2025-06-03T18:53:34.644Z,1748976814.644 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-06-03T18:53:34.654Z,1748976814.654 [SpeedCalculator] Loaded 2025-06-03T18:53:34.655Z,1748976814.655 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-06-03T18:53:34.659Z,1748976814.659 [YawRateCalculator] Loaded 2025-06-03T18:53:34.660Z,1748976814.660 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-06-03T18:53:34.680Z,1748976814.680 [ElevatorOffsetCalculator] Loaded 2025-06-03T18:53:34.680Z,1748976814.680 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-06-03T18:53:34.681Z,1748976814.681 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-06-03T18:53:34.681Z,1748976814.681 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-06-03T18:53:34.855Z,1748976814.855 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-06-03T18:53:34.856Z,1748976814.856 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-06-03T18:53:34.957Z,1748976814.957 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-06-03T18:53:34.957Z,1748976814.957 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-06-03T18:53:35.823Z,1748976815.823 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-06-03T18:53:35.823Z,1748976815.823 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-06-03T18:53:35.837Z,1748976815.837 [NavChart] Loaded 2025-06-03T18:53:35.838Z,1748976815.838 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-06-03T18:53:35.843Z,1748976815.843 [UniversalFixResidualReporter] Loaded 2025-06-03T18:53:35.844Z,1748976815.844 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-06-03T18:53:35.844Z,1748976815.844 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-06-03T18:53:35.845Z,1748976815.845 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-06-03T18:53:36.746Z,1748976816.746 [AHRS_M2] Loaded 2025-06-03T18:53:36.746Z,1748976816.746 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-06-03T18:53:36.999Z,1748976816.999 [BackseatComponent] Loaded 2025-06-03T18:53:36.999Z,1748976816.999 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-06-03T18:53:37.001Z,1748976817.001 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A824E0 2025-06-03T18:53:37.001Z,1748976817.001 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 924 2025-06-03T18:53:37.004Z,1748976817.004 [LcmUniversalReporter] Loaded 2025-06-03T18:53:37.004Z,1748976817.004 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-06-03T18:53:37.756Z,1748976817.756 [BPC1] Loaded 2025-06-03T18:53:37.756Z,1748976817.756 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-06-03T18:53:37.859Z,1748976817.859 [DAT] Loaded 2025-06-03T18:53:37.859Z,1748976817.859 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-06-03T18:53:37.860Z,1748976817.860 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB24E0 2025-06-03T18:53:37.860Z,1748976817.860 [DAT ThreadHandler](INFO): Protected caller Thread ID is 925 2025-06-03T18:53:38.002Z,1748976818.002 [DataOverHttps] Loaded 2025-06-03T18:53:38.002Z,1748976818.002 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-06-03T18:53:38.003Z,1748976818.003 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE24E0 2025-06-03T18:53:38.004Z,1748976818.004 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926 2025-06-03T18:53:38.028Z,1748976818.028 [Depth_Keller] Loaded 2025-06-03T18:53:38.028Z,1748976818.028 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-06-03T18:53:38.033Z,1748976818.033 [DropWeight] Loaded 2025-06-03T18:53:38.034Z,1748976818.034 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-06-03T18:53:38.097Z,1748976818.097 [NAL9602] Loaded 2025-06-03T18:53:38.097Z,1748976818.097 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-06-03T18:53:38.124Z,1748976818.124 [Onboard] Loaded 2025-06-03T18:53:38.124Z,1748976818.124 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-06-03T18:53:38.125Z,1748976818.125 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B124E0 2025-06-03T18:53:38.126Z,1748976818.126 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927 2025-06-03T18:53:38.132Z,1748976818.132 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1 2025-06-03T18:53:38.146Z,1748976818.146 [PowerOnly] Loaded 2025-06-03T18:53:38.146Z,1748976818.146 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2025-06-03T18:53:38.160Z,1748976818.160 [Power24vConverter] Loaded 2025-06-03T18:53:38.161Z,1748976818.161 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-06-03T18:53:38.177Z,1748976818.177 [Radio_Surface] Loaded 2025-06-03T18:53:38.178Z,1748976818.178 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-06-03T18:53:38.179Z,1748976818.179 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B424E0 2025-06-03T18:53:38.179Z,1748976818.179 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928 2025-06-03T18:53:38.195Z,1748976818.195 [Sonardyne_Nano] Loaded 2025-06-03T18:53:38.196Z,1748976818.196 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-06-03T18:53:38.196Z,1748976818.196 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-06-03T18:53:38.197Z,1748976818.197 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-06-03T18:53:38.287Z,1748976818.287 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-06-03T18:53:38.287Z,1748976818.287 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-06-03T18:53:38.362Z,1748976818.362 [VerticalControl](DEBUG): Construct VerticalControl. 2025-06-03T18:53:38.416Z,1748976818.416 [VerticalControl] Loaded 2025-06-03T18:53:38.416Z,1748976818.416 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-06-03T18:53:38.419Z,1748976818.419 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-06-03T18:53:38.465Z,1748976818.465 [HorizontalControl] Loaded 2025-06-03T18:53:38.465Z,1748976818.465 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-06-03T18:53:38.467Z,1748976818.467 [SpeedControl](DEBUG): Construct SpeedControl. 2025-06-03T18:53:38.469Z,1748976818.469 [SpeedControl] Loaded 2025-06-03T18:53:38.469Z,1748976818.469 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-06-03T18:53:38.472Z,1748976818.472 [LoopControl](DEBUG): Construct LoopControl. 2025-06-03T18:53:38.473Z,1748976818.473 [LoopControl] Loaded 2025-06-03T18:53:38.473Z,1748976818.473 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-06-03T18:53:38.474Z,1748976818.474 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-06-03T18:53:38.474Z,1748976818.474 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-06-03T18:53:38.490Z,1748976818.490 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-06-03T18:53:38.491Z,1748976818.491 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-06-03T18:53:38.920Z,1748976818.920 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-06-03T18:53:38.926Z,1748976818.926 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-06-03T18:53:38.929Z,1748976818.929 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-06-03T18:53:38.941Z,1748976818.941 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-06-03T18:53:38.942Z,1748976818.942 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C684E0 2025-06-03T18:53:38.942Z,1748976818.942 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929 2025-06-03T18:53:38.947Z,1748976818.947 [Supervisor](INFO): Main Thread ID is 823 2025-06-03T18:53:38.947Z,1748976818.947 [Supervisor](DEBUG): Running supervisor. 2025-06-03T18:53:38.948Z,1748976818.948 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930 2025-06-03T18:53:38.948Z,1748976818.948 [CommandExec](INFO): Initializing the command executive. 2025-06-03T18:53:38.950Z,1748976818.950 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931 2025-06-03T18:53:38.952Z,1748976818.952 [controlThread ThreadHandler](INFO): Handler Thread ID is 932 2025-06-03T18:53:38.952Z,1748976818.952 [controlThread](DEBUG): Initializing ControlThread 2025-06-03T18:53:38.954Z,1748976818.954 [SBIT](INFO): Initialize SBIT Component. 2025-06-03T18:53:38.954Z,1748976818.954 [SBIT](IMPORTANT): git: 2025-05-29 2025-06-03T18:53:38.955Z,1748976818.955 [SBIT](INFO): git hash: c78c975c7bb2a66b27244d2837f68dff299fa024 2025-06-03T18:53:38.955Z,1748976818.955 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-06-03T18:53:38.956Z,1748976818.956 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2025-06-03T18:53:38.958Z,1748976818.958 [SBIT](INFO): Beginning SBIT in 145.000000 seconds. 2025-06-03T18:53:38.958Z,1748976818.958 [IBIT](INFO): Initialize IBIT Component. 2025-06-03T18:53:38.959Z,1748976818.959 [CBIT](DEBUG): Initialize CBIT Component. 2025-06-03T18:53:38.960Z,1748976818.960 [logger ThreadHandler](INFO): Handler Thread ID is 933 2025-06-03T18:53:38.972Z,1748976818.972 [CBIT](DEBUG): Initialized mux pins. 2025-06-03T18:53:38.972Z,1748976818.972 [CBIT](DEBUG): Initializing the watchdog timer. 2025-06-03T18:53:38.980Z,1748976818.980 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 934 2025-06-03T18:53:38.981Z,1748976818.981 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-06-03T18:53:38.986Z,1748976818.986 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 936 2025-06-03T18:53:38.988Z,1748976818.988 [WetLabsBB2FL](INFO): Powering up 2025-06-03T18:53:38.990Z,1748976818.990 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 938 2025-06-03T18:53:38.996Z,1748976818.996 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-06-03T18:53:38.996Z,1748976818.996 [CBIT](DEBUG): Initializing heartbeat. 2025-06-03T18:53:38.997Z,1748976818.997 [DAT ThreadHandler](INFO): Handler Thread ID is 939 2025-06-03T18:53:38.998Z,1748976818.998 [DAT](INFO): Powering up 2025-06-03T18:53:38.998Z,1748976818.998 [DAT](DEBUG): Initializing DAT. 2025-06-03T18:53:39.001Z,1748976819.001 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 941 2025-06-03T18:53:39.003Z,1748976819.003 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-06-03T18:53:39.024Z,1748976819.024 [Onboard ThreadHandler](INFO): Handler Thread ID is 942 2025-06-03T18:53:39.041Z,1748976819.041 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 943 2025-06-03T18:53:39.062Z,1748976819.062 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 944 2025-06-03T18:53:39.068Z,1748976819.068 [CBIT](DEBUG): Deactivating emergency mode. 2025-06-03T18:53:39.073Z,1748976819.073 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-06-03T18:53:39.073Z,1748976819.073 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-06-03T18:53:39.073Z,1748976819.073 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-06-03T18:53:39.073Z,1748976819.073 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-06-03T18:53:39.073Z,1748976819.073 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-06-03T18:53:39.074Z,1748976819.074 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-06-03T18:53:39.074Z,1748976819.074 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-06-03T18:53:39.074Z,1748976819.074 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-06-03T18:53:39.108Z,1748976819.108 [CBIT](DEBUG): Backplane powered. 2025-06-03T18:53:39.109Z,1748976819.109 [GFScanner](DEBUG): Initializing GFScanner 2025-06-03T18:53:39.109Z,1748976819.109 [GFScanner](DEBUG): Deactivating GF circuits. 2025-06-03T18:53:39.120Z,1748976819.120 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-06-03T18:53:39.120Z,1748976819.120 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-06-03T18:53:39.121Z,1748976819.121 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-06-03T18:53:39.121Z,1748976819.121 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-06-03T18:53:39.121Z,1748976819.121 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-06-03T18:53:39.123Z,1748976819.123 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-06-03T18:53:39.123Z,1748976819.123 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-06-03T18:53:39.127Z,1748976819.127 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-06-03T18:53:39.136Z,1748976819.136 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-06-03T18:53:39.137Z,1748976819.137 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-06-03T18:53:39.138Z,1748976819.138 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-06-03T18:53:39.138Z,1748976819.138 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-06-03T18:53:39.139Z,1748976819.139 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-06-03T18:53:39.139Z,1748976819.139 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-06-03T18:53:39.160Z,1748976819.160 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-06-03T18:53:39.219Z,1748976819.219 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-06-03T18:53:39.233Z,1748976819.233 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-06-03T18:53:39.286Z,1748976819.286 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2025-06-03T18:53:39.286Z,1748976819.286 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-06-03T18:53:39.286Z,1748976819.286 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-06-03T18:53:39.289Z,1748976819.289 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-06-03T18:53:39.448Z,1748976819.448 [Radio_Surface](INFO): Powering up 2025-06-03T18:53:39.599Z,1748976819.599 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2025-06-03T18:53:39.613Z,1748976819.613 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-06-03T18:53:39.614Z,1748976819.614 [Default:A.Wait](DEBUG): Construct Wait. 2025-06-03T18:53:39.632Z,1748976819.632 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-06-03T18:53:39.681Z,1748976819.681 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-06-03T18:53:39.683Z,1748976819.683 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-06-03T18:53:39.705Z,1748976819.705 [Default:E.Execute](DEBUG): Construct Execute. 2025-06-03T18:53:39.708Z,1748976819.708 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2025-06-03T18:53:39.728Z,1748976819.728 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter, 2025-06-03T18:53:39.750Z,1748976819.750 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-06-03T18:53:39.868Z,1748976819.868 [Depth_Keller](INFO): Initializing. 2025-06-03T18:53:39.870Z,1748976819.870 [PowerOnly](INFO): Powering up loadControl 2025-06-03T18:53:39.888Z,1748976819.888 [Power24vConverter](INFO): Powering up. 2025-06-03T18:53:39.889Z,1748976819.889 [Sonardyne_Nano](INFO): Initializing. 2025-06-03T18:53:39.916Z,1748976819.916 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-06-03T18:53:39.966Z,1748976819.966 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:53:39.972Z,1748976819.972 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-06-03T18:53:39.973Z,1748976819.973 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:53:39.980Z,1748976819.980 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-06-03T18:53:39.981Z,1748976819.981 [MassServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:53:39.989Z,1748976819.989 [MassServo](DEBUG): Initializing MassServo. 2025-06-03T18:53:39.989Z,1748976819.989 [RudderServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:53:39.996Z,1748976819.996 [RudderServo](DEBUG): Initializing RudderServo. 2025-06-03T18:53:39.997Z,1748976819.997 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-06-03T18:53:40.005Z,1748976820.005 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-06-03T18:53:40.222Z,1748976820.222 [Depth_Keller](ERROR): Pressure or depth reading out of range: 947.322021 decibar, 0.000000 m 2025-06-03T18:53:40.225Z,1748976820.225 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-06-03T18:53:41.600Z,1748976821.600 [WetLabsBB2FL](INFO): Powering down 2025-06-03T18:53:42.167Z,1748976822.167 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-06-03T18:53:43.405Z,1748976823.405 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213 2025-06-03T18:53:45.785Z,1748976825.785 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-06-03T18:53:51.349Z,1748976831.349 [DAT](INFO): DAT read: 2025-06-03T18:53:51.350Z,1748976831.350 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-06-03T18:53:53.114Z,1748976833.114 [DAT](INFO): DAT read: MF Frequency Band 2025-06-03T18:53:53.115Z,1748976833.115 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-06-03T18:53:53.116Z,1748976833.116 [DAT](INFO): DAT read: Jun 3 2025 18:53:48 2025-06-03T18:53:54.121Z,1748976834.121 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-06-03T18:53:54.122Z,1748976834.122 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-06-03T18:53:54.122Z,1748976834.122 [DAT](INFO): commRate: 1200 2025-06-03T18:53:56.188Z,1748976836.188 [DAT](INFO): entering command mode 2025-06-03T18:53:56.388Z,1748976836.388 [DAT](INFO): DAT read: 2025-06-03T18:53:56.389Z,1748976836.389 [DAT](INFO): DAT read: user:1> 2025-06-03T18:53:56.389Z,1748976836.389 [DAT](INFO): setting verbose to 3 2025-06-03T18:53:56.641Z,1748976836.641 [DAT](INFO): DAT read: user:1> 2025-06-03T18:53:56.642Z,1748976836.642 [DAT](INFO): DAT read: Verbose | 3 2025-06-03T18:53:56.642Z,1748976836.642 [DAT](INFO): set verbose to 3 2025-06-03T18:53:56.642Z,1748976836.642 [DAT](INFO): setting DatVerbose to 27440 2025-06-03T18:53:56.893Z,1748976836.893 [DAT](INFO): DAT read: user:2> 2025-06-03T18:53:56.894Z,1748976836.894 [DAT](INFO): DAT read: DatVerbose | 27440 2025-06-03T18:53:56.894Z,1748976836.894 [DAT](INFO): set DatVerbose to 27440 2025-06-03T18:53:56.894Z,1748976836.894 [DAT](INFO): setting transmit power to 8 2025-06-03T18:53:57.145Z,1748976837.145 [DAT](INFO): DAT read: user:3> 2025-06-03T18:53:57.145Z,1748976837.145 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-06-03T18:53:57.146Z,1748976837.146 [DAT](INFO): set transmit power to 8 2025-06-03T18:53:57.146Z,1748976837.146 [DAT](INFO): setting local address to 5 2025-06-03T18:53:57.397Z,1748976837.397 [DAT](INFO): DAT read: user:4> 2025-06-03T18:53:57.397Z,1748976837.397 [DAT](INFO): DAT read: LocalAddr | 5 2025-06-03T18:53:57.398Z,1748976837.398 [DAT](INFO): set local address to 5 2025-06-03T18:53:57.399Z,1748976837.399 [DAT](INFO): Setting time to: 18:53:57 And date to:6/3/2025 2025-06-03T18:53:57.649Z,1748976837.649 [DAT](INFO): DAT read: user:5> 2025-06-03T18:53:57.649Z,1748976837.649 [DAT](INFO): DAT read: Tue Jun 3, 2025 18:53:57 2025-06-03T18:53:57.650Z,1748976837.650 [DAT](INFO): Local DAT time set to Tue Jun 3, 2025 18:53:57 2025-06-03T18:54:08.501Z,1748976848.501 [NAL9602](INFO): Powering up NAL9602 2025-06-03T18:54:19.408Z,1748976859.408 [NAL9602](INFO): NAL9602 initialized 2025-06-03T18:54:38.388Z,1748976878.388 [NAL9602](INFO): SBD MO Status=0, MOMSN=20940, MT Status=0, MTMSN=0 2025-06-03T18:54:38.388Z,1748976878.388 [NAL9602](INFO): No messages in MT queue 2025-06-03T18:55:03.037Z,1748976903.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185459.00,A,3648.25175,N,12148.08804,W,28.808,91.18,030625,,,A*76 2025-06-03T18:55:03.040Z,1748976903.040 [NAL9602](INFO): GPS fix at 20250603T185459: (36.804196, -121.801467) 2025-06-03T18:55:35.358Z,1748976935.358 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T18:56:01.946Z,1748976961.946 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004553 2025-06-03T18:56:04.466Z,1748976964.466 [SBIT](IMPORTANT): Beginning Startup BIT 2025-06-03T18:56:04.479Z,1748976964.479 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-06-03T18:56:07.980Z,1748976967.980 [ElevatorServo](FAULT): Overload Error 2025-06-03T18:56:07.980Z,1748976967.980 [ElevatorServo] Hardware Fault, FailCount= 1 2025-06-03T18:56:07.980Z,1748976967.980 [ElevatorServo](ERROR): Hardware Fault 2025-06-03T18:56:08.046Z,1748976968.046 [CBIT](ERROR): Hardware Fault in component: ElevatorServo 2025-06-03T18:56:08.229Z,1748976968.229 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-06-03T18:56:08.230Z,1748976968.230 [ElevatorServo](INFO): Powering down 2025-06-03T18:56:09.012Z,1748976969.012 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:56:09.133Z,1748976969.133 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-06-03T18:56:09.308Z,1748976969.308 [CBIT](INFO): Clearing failed state for component ElevatorServo 2025-06-03T18:56:09.308Z,1748976969.308 [ElevatorServo] No Fault, FailCount= 1 2025-06-03T18:56:09.314Z,1748976969.314 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.008057 CHAN A1 (24V): -0.000164 CHAN A2 (12V): -0.005497 CHAN A3 (5V): -0.002728 CHAN B0 (3.3V): -0.000749 CHAN B1 (3.15aV): -0.001097 CHAN B2 (3.15bV): -0.001081 CHAN B3 (GND): 0.000006 OPEN: 0.006862 Full Scale: +/- 1 mA 2025-06-03T18:56:14.272Z,1748976974.272 [ElevatorServo](FAULT): Overload Error 2025-06-03T18:56:14.272Z,1748976974.272 [ElevatorServo] Hardware Fault, FailCount= 2 2025-06-03T18:56:14.272Z,1748976974.272 [ElevatorServo](ERROR): Hardware Fault 2025-06-03T18:56:14.413Z,1748976974.413 [CBIT](ERROR): Hardware Fault in component: ElevatorServo 2025-06-03T18:56:14.649Z,1748976974.649 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-06-03T18:56:14.649Z,1748976974.649 [ElevatorServo](INFO): Powering down 2025-06-03T18:56:15.449Z,1748976975.449 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:56:15.565Z,1748976975.565 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-06-03T18:56:15.597Z,1748976975.597 [CBIT](INFO): Clearing failed state for component ElevatorServo 2025-06-03T18:56:15.597Z,1748976975.597 [ElevatorServo] No Fault, FailCount= 2 2025-06-03T18:56:17.474Z,1748976977.474 [SBIT](ERROR): Could not read elevatorAngleReader_. 2025-06-03T18:56:58.300Z,1748977018.300 [SBIT](CRITICAL): SBIT FAILED 2025-06-03T18:56:58.300Z,1748977018.300 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-06-03T18:56:58.301Z,1748977018.301 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count; 2025-06-03T18:56:58.301Z,1748977018.301 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=1 bool; 2025-06-03T18:56:58.301Z,1748977018.301 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2025-06-03T18:56:58.301Z,1748977018.301 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere; 2025-06-03T18:56:58.301Z,1748977018.301 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=245.649598 cubic_centimeter; 2025-06-03T18:56:58.301Z,1748977018.301 [SBIT](IMPORTANT): VerticalControl.massDefault=31.276186 millimeter; 2025-06-03T18:56:58.303Z,1748977018.303 [CommandExec](FAULT): Scheduling is paused 2025-06-03T18:56:58.303Z,1748977018.303 [CBIT](INFO): Critical error at 20250603T185658 2025-06-03T18:56:58.303Z,1748977018.303 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-06-03T18:56:58.674Z,1748977018.674 [MissionManager](IMPORTANT): Started mission Startup 2025-06-03T18:56:58.675Z,1748977018.675 [Startup] Running Loop=1 2025-06-03T18:56:58.675Z,1748977018.675 [Startup](DEBUG): Aggregate::initialize Startup 2025-06-03T18:56:58.675Z,1748977018.675 [Startup:A.GoToSurface] Running Loop=1 2025-06-03T18:56:58.675Z,1748977018.675 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-06-03T18:56:58.675Z,1748977018.675 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-06-03T18:56:58.676Z,1748977018.676 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-06-03T18:56:58.676Z,1748977018.676 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-06-03T18:56:58.677Z,1748977018.677 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-06-03T18:56:58.677Z,1748977018.677 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-06-03T18:56:58.677Z,1748977018.677 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-06-03T18:56:58.679Z,1748977018.679 [Startup:StartupSatComms] Running Loop=1 2025-06-03T18:56:58.679Z,1748977018.679 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-06-03T18:56:58.679Z,1748977018.679 [Startup:StartupSatComms:A] Running Loop=1 2025-06-03T18:56:59.088Z,1748977019.088 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-06-03T18:57:00.711Z,1748977020.711 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185656.00,A,3648.46058,N,12147.26873,W,4.937,49.10,030625,,,A*4D 2025-06-03T18:57:00.713Z,1748977020.713 [NAL9602](INFO): GPS fix at 20250603T185656: (36.807676, -121.787812) 2025-06-03T18:57:00.724Z,1748977020.724 [Startup:StartupSatComms:A] Stopped 2025-06-03T18:57:00.724Z,1748977020.724 [Startup:StartupSatComms:B] Running Loop=1 2025-06-03T18:57:01.128Z,1748977021.128 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-06-03T18:57:08.467Z,1748977028.467 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250603T184648/Courier0006.lzma 2025-06-03T18:57:09.466Z,1748977029.466 [DataOverHttps](INFO): Moved sent file to Logs/20250603T184648/Courier0006.lzma.bak 2025-06-03T18:57:09.466Z,1748977029.466 [DataOverHttps](INFO): SBD MOMSN=25085862 2025-06-03T18:57:15.264Z,1748977035.264 [NAL9602](INFO): SBD MO Status=0, MOMSN=20941, MT Status=0, MTMSN=0 2025-06-03T18:57:15.264Z,1748977035.264 [NAL9602](INFO): No messages in MT queue 2025-06-03T18:57:25.660Z,1748977045.660 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20250603T185326/Courier0000.lzma 2025-06-03T18:57:26.662Z,1748977046.662 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Courier0000.lzma.bak 2025-06-03T18:57:26.662Z,1748977046.662 [DataOverHttps](INFO): SBD MOMSN=25085864 2025-06-03T18:57:43.987Z,1748977063.987 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250603T184648/Express0007.lzma 2025-06-03T18:57:44.990Z,1748977064.990 [DataOverHttps](INFO): Moved sent file to Logs/20250603T184648/Express0007.lzma.bak 2025-06-03T18:57:44.990Z,1748977064.990 [DataOverHttps](INFO): SBD MOMSN=25085869 2025-06-03T18:57:45.972Z,1748977065.972 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T18:58:00.951Z,1748977080.951 [Startup:StartupSatComms:B](INFO): Timed out from 2025-06-03T18:57:00.7Z 2025-06-03T18:58:00.951Z,1748977080.951 [Startup:StartupSatComms:B] Stopped 2025-06-03T18:58:00.951Z,1748977080.951 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-06-03T18:58:00.951Z,1748977080.951 [Startup:StartupSatComms] Stopped 2025-06-03T18:58:00.951Z,1748977080.951 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-06-03T18:58:00.952Z,1748977080.952 [Startup](INFO): Completed Startup 2025-06-03T18:58:00.952Z,1748977080.952 [MissionManager](INFO): Startup is completed. 2025-06-03T18:58:00.953Z,1748977080.953 [MissionManager](INFO): Uninitializing Mission Startup 2025-06-03T18:58:00.953Z,1748977080.953 [Startup] Stopped 2025-06-03T18:58:00.953Z,1748977080.953 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-06-03T18:58:00.953Z,1748977080.953 [Startup:A.GoToSurface] Stopped 2025-06-03T18:58:00.953Z,1748977080.953 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-06-03T18:58:01.182Z,1748977081.182 [DataOverHttps](INFO): Sending 1194 bytes from file Logs/20250603T185326/Express0001.lzma 2025-06-03T18:58:01.364Z,1748977081.364 [MissionManager](IMPORTANT): Started mission Default 2025-06-03T18:58:01.365Z,1748977081.365 [Default] Running Loop=1 2025-06-03T18:58:01.365Z,1748977081.365 [Default](DEBUG): Aggregate::initialize Default 2025-06-03T18:58:01.365Z,1748977081.365 [Default:B.GoToSurface] Running Loop=1 2025-06-03T18:58:01.365Z,1748977081.365 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-06-03T18:58:01.365Z,1748977081.365 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-06-03T18:58:01.366Z,1748977081.366 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-06-03T18:58:01.366Z,1748977081.366 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-06-03T18:58:01.366Z,1748977081.366 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-06-03T18:58:01.366Z,1748977081.366 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-06-03T18:58:01.367Z,1748977081.367 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-06-03T18:58:01.367Z,1748977081.367 [Default:A.Wait] Running Loop=1 2025-06-03T18:58:01.367Z,1748977081.367 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-06-03T18:58:02.194Z,1748977082.194 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Express0001.lzma.bak 2025-06-03T18:58:02.194Z,1748977082.194 [DataOverHttps](INFO): SBD MOMSN=25085871 2025-06-03T18:58:14.691Z,1748977094.691 [Default:A.Wait](INFO): Done Waiting. 2025-06-03T18:58:14.691Z,1748977094.691 [Default:A.Wait] Stopped 2025-06-03T18:58:14.691Z,1748977094.691 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T18:58:15.092Z,1748977095.092 [Default:CheckIn] Running Loop=1 2025-06-03T18:58:15.092Z,1748977095.092 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-03T18:58:15.092Z,1748977095.092 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-03T18:58:15.499Z,1748977095.499 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-06-03T18:58:17.109Z,1748977097.109 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185813.00,A,3648.50806,N,12147.14347,W,5.482,111.33,030625,,,A*74 2025-06-03T18:58:17.111Z,1748977097.111 [NAL9602](INFO): GPS fix at 20250603T185813: (36.808468, -121.785725) 2025-06-03T18:58:17.122Z,1748977097.122 [Default:CheckIn:Read_GPS] Stopped 2025-06-03T18:58:17.122Z,1748977097.122 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-03T18:58:17.540Z,1748977097.540 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-06-03T18:58:24.531Z,1748977104.531 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250603T185326/Courier0004.lzma 2025-06-03T18:58:25.534Z,1748977105.534 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Courier0004.lzma.bak 2025-06-03T18:58:25.534Z,1748977105.534 [DataOverHttps](INFO): SBD MOMSN=25085893 2025-06-03T18:58:41.408Z,1748977121.408 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20250603T185326/Express0005.lzma 2025-06-03T18:58:42.410Z,1748977122.410 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Express0005.lzma.bak 2025-06-03T18:58:42.410Z,1748977122.410 [DataOverHttps](INFO): SBD MOMSN=25085896 2025-06-03T18:58:43.790Z,1748977123.790 [Default:CheckIn:Read_Iridium] Stopped 2025-06-03T18:58:43.790Z,1748977123.790 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-03T18:58:43.790Z,1748977123.790 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-03T18:59:21.665Z,1748977161.665 [DataOverHttps](IMPORTANT): SBD MTMSN=20250603T185920 2025-06-03T18:59:29.212Z,1748977169.212 [DataOverHttps](INFO): Received command: failc 2025-06-03T18:59:29.257Z,1748977169.257 [CommandExec](IMPORTANT): got command failComponent 2025-06-03T18:59:29.257Z,1748977169.257 [CommandExec](IMPORTANT): Failed components: 2025-06-03T18:59:29.257Z,1748977169.257 [CommandExec](IMPORTANT): No failed Components. 2025-06-03T19:00:10.636Z,1748977210.636 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-06-03T19:00:10.637Z,1748977210.637 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-06-03T19:00:10.641Z,1748977210.641 [BPC1](INFO): Received data from all battery sticks. 2025-06-03T19:00:16.286Z,1748977216.286 [NAL9602](INFO): SBD MO Status=2, MOMSN=20942, MT Status=2, MTMSN=0 2025-06-03T19:00:16.287Z,1748977216.287 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T19:00:35.273Z,1748977235.273 [NAL9602](INFO): SBD MO Status=2, MOMSN=20942, MT Status=2, MTMSN=0 2025-06-03T19:00:35.274Z,1748977235.274 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T19:01:09.205Z,1748977269.205 [NAL9602](INFO): SBD MO Status=2, MOMSN=20942, MT Status=2, MTMSN=0 2025-06-03T19:01:09.205Z,1748977269.205 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T19:02:19.510Z,1748977339.510 [NAL9602](INFO): SBD MO Status=2, MOMSN=20942, MT Status=2, MTMSN=0 2025-06-03T19:02:19.510Z,1748977339.510 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T19:02:29.199Z,1748977349.199 [NAL9602](INFO): SBD MO Status=0, MOMSN=20942, MT Status=0, MTMSN=0 2025-06-03T19:02:29.199Z,1748977349.199 [NAL9602](INFO): No messages in MT queue 2025-06-03T19:02:59.911Z,1748977379.911 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T19:03:44.361Z,1748977424.361 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-03T19:03:44.361Z,1748977424.361 [Default:CheckIn:C.Wait] Stopped 2025-06-03T19:03:44.361Z,1748977424.361 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T19:03:44.361Z,1748977424.361 [Default:CheckIn:D] Running Loop=1 2025-06-03T19:03:44.766Z,1748977424.766 [Default:CheckIn:D] Stopped 2025-06-03T19:03:44.766Z,1748977424.766 [Default:CheckIn:E] Running Loop=1 2025-06-03T19:03:45.171Z,1748977425.171 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.723352 min 2025-06-03T19:03:45.171Z,1748977425.171 [Default:CheckIn:E] Stopped 2025-06-03T19:03:45.171Z,1748977425.171 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-03T19:03:45.171Z,1748977425.171 [Default:CheckIn] Stopped 2025-06-03T19:03:45.171Z,1748977425.171 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-03T19:03:45.172Z,1748977425.172 [Default:CheckIn](INFO): Running loop #2 2025-06-03T19:03:45.172Z,1748977425.172 [Default:CheckIn] Running Loop=2 2025-06-03T19:03:45.172Z,1748977425.172 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-03T19:03:45.172Z,1748977425.172 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-03T19:03:47.187Z,1748977427.187 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190346.00,A,3648.15677,N,12147.21600,W,1.050,217.80,030625,,,A*70 2025-06-03T19:03:47.189Z,1748977427.189 [NAL9602](INFO): GPS fix at 20250603T190346: (36.802613, -121.786933) 2025-06-03T19:03:47.204Z,1748977427.204 [Default:CheckIn:Read_GPS] Stopped 2025-06-03T19:03:47.205Z,1748977427.205 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-03T19:03:54.168Z,1748977434.168 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20250603T185326/Courier0007.lzma 2025-06-03T19:03:55.170Z,1748977435.170 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Courier0007.lzma.bak 2025-06-03T19:03:55.170Z,1748977435.170 [DataOverHttps](INFO): SBD MOMSN=25085930 2025-06-03T19:04:03.350Z,1748977443.350 [NAL9602](INFO): SBD MO Status=0, MOMSN=20943, MT Status=0, MTMSN=0 2025-06-03T19:04:03.351Z,1748977443.351 [NAL9602](INFO): No messages in MT queue 2025-06-03T19:04:11.020Z,1748977451.020 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20250603T185326/Express0008.lzma 2025-06-03T19:04:12.024Z,1748977452.024 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Express0008.lzma.bak 2025-06-03T19:04:12.024Z,1748977452.024 [DataOverHttps](INFO): SBD MOMSN=25085933 2025-06-03T19:04:13.449Z,1748977453.449 [Default:CheckIn:Read_Iridium] Stopped 2025-06-03T19:04:13.449Z,1748977453.449 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-03T19:04:13.449Z,1748977453.449 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-03T19:04:34.051Z,1748977474.051 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T19:08:25.045Z,1748977705.045 [DataOverHttps](IMPORTANT): SBD MTMSN=20250603T190823 2025-06-03T19:08:32.496Z,1748977712.496 [DataOverHttps](INFO): Received command: restart sys 2025-06-03T19:08:32.521Z,1748977712.521 [CommandExec](IMPORTANT): got command restart system 2025-06-03T19:08:34.712Z,1748977714.712 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-03T19:08:34.713Z,1748977714.713 [CommandExec](INFO): Uninitializing the command executive. 2025-06-03T19:08:34.713Z,1748977714.713 [CommandExec](INFO): Uninitializing the command scheduler. 2025-06-03T19:08:34.714Z,1748977714.714 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-06-03T19:08:34.832Z,1748977714.832 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-06-03T19:08:34.832Z,1748977714.832 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-06-03T19:08:34.832Z,1748977714.832 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-06-03T19:08:34.833Z,1748977714.833 [NavChartDb](INFO): Join timeout helper Thread ID is 1047 2025-06-03T19:08:34.932Z,1748977714.932 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-03T19:08:34.932Z,1748977714.932 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-06-03T19:08:34.936Z,1748977714.936 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-06-03T19:08:34