2025-09-24T18:32:14.185Z,1758738734.185 [Supervisor](DEBUG): Initializing supervisor.
2025-09-24T18:32:14.190Z,1758738734.190 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-09-24T18:32:14.190Z,1758738734.190 [SyncHandler](INFO): Protected caller Thread ID is 6189
2025-09-24T18:32:14.191Z,1758738734.191 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-09-24T18:32:14.192Z,1758738734.192 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-09-24T18:32:14.192Z,1758738734.192 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6190
2025-09-24T18:32:14.197Z,1758738734.197 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-09-24T18:32:14.217Z,1758738734.217 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-09-24T18:32:14.218Z,1758738734.218 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-09-24T18:32:14.218Z,1758738734.218 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6191
2025-09-24T18:32:14.222Z,1758738734.222 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-09-24T18:32:14.223Z,1758738734.223 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-09-24T18:32:14.224Z,1758738734.224 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6192
2025-09-24T18:32:14.226Z,1758738734.226 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-09-24T18:32:14.227Z,1758738734.227 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-09-24T18:32:14.227Z,1758738734.227 [logger ThreadHandler](INFO): Protected caller Thread ID is 6193
2025-09-24T18:32:14.231Z,1758738734.231 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-09-24T18:32:14.231Z,1758738734.231 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-09-24T18:32:14.233Z,1758738734.233 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-09-24T18:32:14.339Z,1758738734.339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-09-24T18:32:14.339Z,1758738734.339 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-09-24T18:32:14.577Z,1758738734.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-09-24T18:32:14.577Z,1758738734.577 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-09-24T18:32:14.847Z,1758738734.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-09-24T18:32:14.848Z,1758738734.848 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-09-24T18:32:14.964Z,1758738734.964 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-09-24T18:32:14.964Z,1758738734.964 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-09-24T18:32:15.722Z,1758738735.722 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-09-24T18:32:15.722Z,1758738735.722 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-09-24T18:32:16.627Z,1758738736.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-09-24T18:32:16.628Z,1758738736.628 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-09-24T18:32:17.170Z,1758738737.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-09-24T18:32:17.171Z,1758738737.171 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-09-24T18:32:17.606Z,1758738737.606 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-09-24T18:32:17.607Z,1758738737.607 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-09-24T18:32:17.961Z,1758738737.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-09-24T18:32:17.961Z,1758738737.961 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-09-24T18:32:18.356Z,1758738738.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-09-24T18:32:18.357Z,1758738738.357 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-09-24T18:32:18.591Z,1758738738.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-09-24T18:32:18.591Z,1758738738.591 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-09-24T18:32:18.745Z,1758738738.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-09-24T18:32:18.745Z,1758738738.745 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-09-24T18:32:18.848Z,1758738738.848 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-09-24T18:32:18.848Z,1758738738.848 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-09-24T18:32:18.938Z,1758738738.938 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-09-24T18:32:19.129Z,1758738739.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-09-24T18:32:19.130Z,1758738739.130 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-09-24T18:32:19.384Z,1758738739.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-09-24T18:32:19.386Z,1758738739.386 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-09-24T18:32:19.387Z,1758738739.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-09-24T18:32:19.481Z,1758738739.481 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-09-24T18:32:19.761Z,1758738739.761 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-09-24T18:32:19.762Z,1758738739.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-09-24T18:32:19.856Z,1758738739.856 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-09-24T18:32:20.034Z,1758738740.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-09-24T18:32:20.145Z,1758738740.145 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-09-24T18:32:20.263Z,1758738740.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-09-24T18:32:20.384Z,1758738740.384 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-09-24T18:32:20.488Z,1758738740.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-09-24T18:32:20.654Z,1758738740.654 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-09-24T18:32:20.761Z,1758738740.761 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-09-24T18:32:20.855Z,1758738740.855 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-09-24T18:32:20.963Z,1758738740.963 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-09-24T18:32:21.061Z,1758738741.061 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2025-09-24T18:32:21.061Z,1758738741.061 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-09-24T18:32:21.069Z,1758738741.069 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-09-24T18:32:21.250Z,1758738741.250 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-09-24T18:32:21.251Z,1758738741.251 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-09-24T18:32:21.416Z,1758738741.416 [BuoyancyServo] Loaded
2025-09-24T18:32:21.416Z,1758738741.416 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-09-24T18:32:21.440Z,1758738741.440 [ElevatorServo] Loaded
2025-09-24T18:32:21.440Z,1758738741.440 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-09-24T18:32:21.463Z,1758738741.463 [MassServo] Loaded
2025-09-24T18:32:21.463Z,1758738741.463 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-09-24T18:32:21.486Z,1758738741.486 [RudderServo] Loaded
2025-09-24T18:32:21.486Z,1758738741.486 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-09-24T18:32:21.504Z,1758738741.504 [ThrusterHE] Loaded
2025-09-24T18:32:21.504Z,1758738741.504 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-09-24T18:32:21.504Z,1758738741.504 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-09-24T18:32:21.505Z,1758738741.505 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-09-24T18:32:22.284Z,1758738742.284 [SBIT](DEBUG): Construct Startup Built In Test.
2025-09-24T18:32:22.298Z,1758738742.298 [SBIT] Loaded
2025-09-24T18:32:22.299Z,1758738742.299 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-09-24T18:32:22.301Z,1758738742.301 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-09-24T18:32:22.323Z,1758738742.323 [IBIT] Loaded
2025-09-24T18:32:22.323Z,1758738742.323 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-09-24T18:32:22.328Z,1758738742.328 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-09-24T18:32:22.641Z,1758738742.641 [CBIT] Loaded
2025-09-24T18:32:22.642Z,1758738742.642 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-09-24T18:32:22.673Z,1758738742.673 [GFScanner] Loaded
2025-09-24T18:32:22.673Z,1758738742.673 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-09-24T18:32:22.674Z,1758738742.674 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-09-24T18:32:22.674Z,1758738742.674 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-09-24T18:32:22.847Z,1758738742.847 [CTD_Seabird] Loaded
2025-09-24T18:32:22.847Z,1758738742.847 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-09-24T18:32:22.848Z,1758738742.848 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406874E0
2025-09-24T18:32:22.849Z,1758738742.849 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6281
2025-09-24T18:32:22.884Z,1758738742.884 [ESPComponent] Loaded
2025-09-24T18:32:22.884Z,1758738742.884 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-09-24T18:32:22.907Z,1758738742.907 [PAR_Licor] Loaded
2025-09-24T18:32:22.907Z,1758738742.907 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-09-24T18:32:22.953Z,1758738742.953 [WetLabsBB2FL] Loaded
2025-09-24T18:32:22.953Z,1758738742.953 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-09-24T18:32:22.954Z,1758738742.954 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B74E0
2025-09-24T18:32:22.954Z,1758738742.954 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6282
2025-09-24T18:32:22.955Z,1758738742.955 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-09-24T18:32:22.956Z,1758738742.956 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-09-24T18:32:23.007Z,1758738743.007 [DepthRateCalculator] Loaded
2025-09-24T18:32:23.008Z,1758738743.008 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-09-24T18:32:23.013Z,1758738743.013 [PitchRateCalculator] Loaded
2025-09-24T18:32:23.013Z,1758738743.013 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-09-24T18:32:23.023Z,1758738743.023 [SpeedCalculator] Loaded
2025-09-24T18:32:23.024Z,1758738743.024 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-09-24T18:32:23.028Z,1758738743.028 [YawRateCalculator] Loaded
2025-09-24T18:32:23.029Z,1758738743.029 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-09-24T18:32:23.049Z,1758738743.049 [ElevatorOffsetCalculator] Loaded
2025-09-24T18:32:23.049Z,1758738743.049 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-09-24T18:32:23.049Z,1758738743.049 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-09-24T18:32:23.050Z,1758738743.050 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-09-24T18:32:23.189Z,1758738743.189 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-09-24T18:32:23.189Z,1758738743.189 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-09-24T18:32:23.220Z,1758738743.220 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-09-24T18:32:23.220Z,1758738743.220 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-09-24T18:32:23.336Z,1758738743.336 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-09-24T18:32:23.337Z,1758738743.337 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-09-24T18:32:23.351Z,1758738743.351 [NavChart] Loaded
2025-09-24T18:32:23.351Z,1758738743.351 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-09-24T18:32:23.357Z,1758738743.357 [UniversalFixResidualReporter] Loaded
2025-09-24T18:32:23.357Z,1758738743.357 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-09-24T18:32:23.357Z,1758738743.357 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-09-24T18:32:23.358Z,1758738743.358 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-09-24T18:32:23.849Z,1758738743.849 [AHRS_M2] Loaded
2025-09-24T18:32:23.849Z,1758738743.849 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-09-24T18:32:23.889Z,1758738743.889 [BackseatComponent] Loaded
2025-09-24T18:32:23.889Z,1758738743.889 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-09-24T18:32:23.890Z,1758738743.890 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0
2025-09-24T18:32:23.891Z,1758738743.891 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 6283
2025-09-24T18:32:23.893Z,1758738743.893 [LcmUniversalReporter] Loaded
2025-09-24T18:32:23.894Z,1758738743.894 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-09-24T18:32:24.662Z,1758738744.662 [BPC1] Loaded
2025-09-24T18:32:24.662Z,1758738744.662 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-09-24T18:32:24.765Z,1758738744.765 [DAT] Loaded
2025-09-24T18:32:24.766Z,1758738744.766 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-09-24T18:32:24.767Z,1758738744.767 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0
2025-09-24T18:32:24.767Z,1758738744.767 [DAT ThreadHandler](INFO): Protected caller Thread ID is 6284
2025-09-24T18:32:24.841Z,1758738744.841 [DataOverHttps] Loaded
2025-09-24T18:32:24.841Z,1758738744.841 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-09-24T18:32:24.842Z,1758738744.842 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0
2025-09-24T18:32:24.843Z,1758738744.843 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6285
2025-09-24T18:32:24.867Z,1758738744.867 [Depth_Keller] Loaded
2025-09-24T18:32:24.867Z,1758738744.867 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-09-24T18:32:24.872Z,1758738744.872 [DropWeight] Loaded
2025-09-24T18:32:24.873Z,1758738744.873 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-09-24T18:32:24.916Z,1758738744.916 [DVL_micro] Loaded
2025-09-24T18:32:24.916Z,1758738744.916 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2025-09-24T18:32:24.981Z,1758738744.981 [NAL9602] Loaded
2025-09-24T18:32:24.981Z,1758738744.981 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-09-24T18:32:25.008Z,1758738745.008 [Onboard] Loaded
2025-09-24T18:32:25.008Z,1758738745.008 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-09-24T18:32:25.009Z,1758738745.009 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B154E0
2025-09-24T18:32:25.009Z,1758738745.009 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6286
2025-09-24T18:32:25.015Z,1758738745.015 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2025-09-24T18:32:25.029Z,1758738745.029 [PowerOnly] Loaded
2025-09-24T18:32:25.030Z,1758738745.030 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-09-24T18:32:25.044Z,1758738745.044 [Power24vConverter] Loaded
2025-09-24T18:32:25.044Z,1758738745.044 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-09-24T18:32:25.061Z,1758738745.061 [Radio_Surface] Loaded
2025-09-24T18:32:25.061Z,1758738745.061 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-09-24T18:32:25.062Z,1758738745.062 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B454E0
2025-09-24T18:32:25.062Z,1758738745.062 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6287
2025-09-24T18:32:25.078Z,1758738745.078 [Sonardyne_Nano] Loaded
2025-09-24T18:32:25.078Z,1758738745.078 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-09-24T18:32:25.079Z,1758738745.079 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-09-24T18:32:25.079Z,1758738745.079 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-09-24T18:32:25.141Z,1758738745.141 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-09-24T18:32:25.141Z,1758738745.141 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-09-24T18:32:25.197Z,1758738745.197 [VerticalControl](DEBUG): Construct VerticalControl.
2025-09-24T18:32:25.249Z,1758738745.249 [VerticalControl] Loaded
2025-09-24T18:32:25.250Z,1758738745.250 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-09-24T18:32:25.253Z,1758738745.253 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-09-24T18:32:25.298Z,1758738745.298 [HorizontalControl] Loaded
2025-09-24T18:32:25.298Z,1758738745.298 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-09-24T18:32:25.301Z,1758738745.301 [SpeedControl](DEBUG): Construct SpeedControl.
2025-09-24T18:32:25.303Z,1758738745.303 [SpeedControl] Loaded
2025-09-24T18:32:25.303Z,1758738745.303 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-09-24T18:32:25.306Z,1758738745.306 [LoopControl](DEBUG): Construct LoopControl.
2025-09-24T18:32:25.306Z,1758738745.306 [LoopControl] Loaded
2025-09-24T18:32:25.307Z,1758738745.307 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-09-24T18:32:25.307Z,1758738745.307 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-09-24T18:32:25.308Z,1758738745.308 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-09-24T18:32:25.318Z,1758738745.318 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-09-24T18:32:25.319Z,1758738745.319 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-09-24T18:32:25.671Z,1758738745.671 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-09-24T18:32:25.677Z,1758738745.677 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-09-24T18:32:25.680Z,1758738745.680 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-09-24T18:32:25.692Z,1758738745.692 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-09-24T18:32:25.693Z,1758738745.693 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C6D4E0
2025-09-24T18:32:25.693Z,1758738745.693 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6288
2025-09-24T18:32:25.697Z,1758738745.697 [Supervisor](INFO): Main Thread ID is 6016
2025-09-24T18:32:25.697Z,1758738745.697 [Supervisor](DEBUG): Running supervisor.
2025-09-24T18:32:25.698Z,1758738745.698 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6289
2025-09-24T18:32:25.699Z,1758738745.699 [CommandExec](INFO): Initializing the command executive.
2025-09-24T18:32:25.700Z,1758738745.700 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6290
2025-09-24T18:32:25.702Z,1758738745.702 [controlThread ThreadHandler](INFO): Handler Thread ID is 6291
2025-09-24T18:32:25.703Z,1758738745.703 [controlThread](DEBUG): Initializing ControlThread
2025-09-24T18:32:25.705Z,1758738745.705 [SBIT](INFO): Initialize SBIT Component.
2025-09-24T18:32:25.705Z,1758738745.705 [SBIT](IMPORTANT): git: 2025-09-02
2025-09-24T18:32:25.705Z,1758738745.705 [SBIT](INFO): git hash: 79ab46e6183b98c19ab2829623a4adc5bf79cefb
2025-09-24T18:32:25.706Z,1758738745.706 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-09-24T18:32:25.707Z,1758738745.707 [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-09-24T18:32:25.708Z,1758738745.708 [SBIT](INFO): Beginning SBIT in 143.000000 seconds.
2025-09-24T18:32:25.709Z,1758738745.709 [IBIT](INFO): Initialize IBIT Component.
2025-09-24T18:32:25.710Z,1758738745.710 [CBIT](DEBUG): Initialize CBIT Component.
2025-09-24T18:32:25.711Z,1758738745.711 [logger ThreadHandler](INFO): Handler Thread ID is 6292
2025-09-24T18:32:25.722Z,1758738745.722 [CBIT](DEBUG): Initialized mux pins.
2025-09-24T18:32:25.722Z,1758738745.722 [CBIT](DEBUG): Initializing the watchdog timer.
2025-09-24T18:32:25.731Z,1758738745.731 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6293
2025-09-24T18:32:25.731Z,1758738745.731 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-09-24T18:32:25.736Z,1758738745.736 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6295
2025-09-24T18:32:25.739Z,1758738745.739 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:32:25.740Z,1758738745.740 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 6297
2025-09-24T18:32:25.746Z,1758738745.746 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-09-24T18:32:25.747Z,1758738745.747 [CBIT](DEBUG): Initializing heartbeat.
2025-09-24T18:32:25.748Z,1758738745.748 [DAT ThreadHandler](INFO): Handler Thread ID is 6298
2025-09-24T18:32:25.749Z,1758738745.749 [DAT](INFO): Powering up
2025-09-24T18:32:25.749Z,1758738745.749 [DAT](DEBUG): Initializing DAT.
2025-09-24T18:32:25.752Z,1758738745.752 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6300
2025-09-24T18:32:25.753Z,1758738745.753 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-09-24T18:32:25.775Z,1758738745.775 [Onboard ThreadHandler](INFO): Handler Thread ID is 6301
2025-09-24T18:32:25.792Z,1758738745.792 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6302
2025-09-24T18:32:25.813Z,1758738745.813 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6303
2025-09-24T18:32:25.816Z,1758738745.816 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-09-24T18:32:25.816Z,1758738745.816 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-09-24T18:32:25.816Z,1758738745.816 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-09-24T18:32:25.816Z,1758738745.816 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-09-24T18:32:25.816Z,1758738745.816 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-09-24T18:32:25.816Z,1758738745.816 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-09-24T18:32:25.817Z,1758738745.817 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-09-24T18:32:25.817Z,1758738745.817 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-09-24T18:32:25.818Z,1758738745.818 [CBIT](DEBUG): Deactivating emergency mode.
2025-09-24T18:32:25.858Z,1758738745.858 [CBIT](DEBUG): Backplane powered.
2025-09-24T18:32:25.859Z,1758738745.859 [GFScanner](DEBUG): Initializing GFScanner
2025-09-24T18:32:25.859Z,1758738745.859 [GFScanner](DEBUG): Deactivating GF circuits.
2025-09-24T18:32:25.871Z,1758738745.871 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-09-24T18:32:25.871Z,1758738745.871 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-09-24T18:32:25.871Z,1758738745.871 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-09-24T18:32:25.872Z,1758738745.872 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-09-24T18:32:25.872Z,1758738745.872 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-09-24T18:32:25.873Z,1758738745.873 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-09-24T18:32:25.874Z,1758738745.874 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-09-24T18:32:25.877Z,1758738745.877 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-09-24T18:32:25.887Z,1758738745.887 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-09-24T18:32:25.888Z,1758738745.888 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-09-24T18:32:25.888Z,1758738745.888 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-09-24T18:32:25.889Z,1758738745.889 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-09-24T18:32:25.890Z,1758738745.890 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-09-24T18:32:25.890Z,1758738745.890 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-09-24T18:32:25.900Z,1758738745.900 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-09-24T18:32:25.983Z,1758738745.983 [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-09-24T18:32:25.987Z,1758738745.987 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-09-24T18:32:26.045Z,1758738746.045 [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-09-24T18:32:26.045Z,1758738746.045 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-09-24T18:32:26.046Z,1758738746.046 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-09-24T18:32:26.047Z,1758738746.047 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-09-24T18:32:26.199Z,1758738746.199 [Radio_Surface](INFO): Powering up
2025-09-24T18:32:26.385Z,1758738746.385 [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-09-24T18:32:26.407Z,1758738746.407 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-09-24T18:32:26.408Z,1758738746.408 [Default:A.Wait](DEBUG): Construct Wait.
2025-09-24T18:32:26.410Z,1758738746.410 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-09-24T18:32:26.465Z,1758738746.465 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-09-24T18:32:26.475Z,1758738746.475 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-09-24T18:32:26.489Z,1758738746.489 [Default:E.Execute](DEBUG): Construct Execute.
2025-09-24T18:32:26.499Z,1758738746.499 [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-09-24T18:32:26.512Z,1758738746.512 [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-09-24T18:32:26.541Z,1758738746.541 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-09-24T18:32:26.603Z,1758738746.603 [Depth_Keller](INFO): Initializing.
2025-09-24T18:32:26.612Z,1758738746.612 [Power24vConverter](INFO): Powering up.
2025-09-24T18:32:26.613Z,1758738746.613 [Sonardyne_Nano](INFO): Initializing.
2025-09-24T18:32:26.639Z,1758738746.639 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-09-24T18:32:26.665Z,1758738746.665 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-09-24T18:32:26.671Z,1758738746.671 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-09-24T18:32:26.672Z,1758738746.672 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-09-24T18:32:26.679Z,1758738746.679 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-09-24T18:32:26.680Z,1758738746.680 [MassServo](DEBUG): Initializing EZServoServo.
2025-09-24T18:32:26.687Z,1758738746.687 [MassServo](DEBUG): Initializing MassServo.
2025-09-24T18:32:26.687Z,1758738746.687 [RudderServo](DEBUG): Initializing EZServoServo.
2025-09-24T18:32:26.695Z,1758738746.695 [RudderServo](DEBUG): Initializing RudderServo.
2025-09-24T18:32:26.695Z,1758738746.695 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-09-24T18:32:26.703Z,1758738746.703 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-09-24T18:32:26.972Z,1758738746.972 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2025-09-24T18:32:26.972Z,1758738746.972 [DropWeight] Hardware Fault, FailCount= 1
2025-09-24T18:32:26.972Z,1758738746.972 [DropWeight](ERROR): Hardware Fault
2025-09-24T18:32:26.973Z,1758738746.973 [PowerOnly](INFO): Powering up loadControl
2025-09-24T18:32:27.016Z,1758738747.016 [CommandExec](FAULT): Scheduling is paused
2025-09-24T18:32:27.017Z,1758738747.017 [CBIT](INFO): Critical error at 20250924T183226
2025-09-24T18:32:27.017Z,1758738747.017 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-09-24T18:32:27.027Z,1758738747.027 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-09-24T18:32:27.028Z,1758738747.028 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-09-24T18:32:27.356Z,1758738747.356 [CBIT](INFO): Critical error at 20250924T183227
2025-09-24T18:32:28.546Z,1758738748.546 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-09-24T18:32:30.200Z,1758738750.200 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-09-24T18:32:31.039Z,1758738751.039 [WetLabsBB2FL] Communications Fault, FailCount= 1
2025-09-24T18:32:31.039Z,1758738751.039 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:32:31.274Z,1758738751.274 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:32:31.539Z,1758738751.539 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:32:32.470Z,1758738752.470 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:32:32.470Z,1758738752.470 [WetLabsBB2FL] No Fault, FailCount= 1
2025-09-24T18:32:32.752Z,1758738752.752 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:32:37.851Z,1758738757.851 [DAT](INFO): DAT read: 

2025-09-24T18:32:37.852Z,1758738757.852 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2025-09-24T18:32:38.046Z,1758738758.046 [WetLabsBB2FL] Communications Fault, FailCount= 2
2025-09-24T18:32:38.046Z,1758738758.046 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:32:38.303Z,1758738758.303 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:32:38.547Z,1758738758.547 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:32:39.507Z,1758738759.507 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:32:39.507Z,1758738759.507 [WetLabsBB2FL] No Fault, FailCount= 2
2025-09-24T18:32:39.760Z,1758738759.760 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:32:39.867Z,1758738759.867 [DAT](INFO): DAT read: MF Frequency Band

2025-09-24T18:32:39.868Z,1758738759.868 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2025-09-24T18:32:39.869Z,1758738759.869 [DAT](INFO): DAT read: Sep 24 2025 18:32:34 

2025-09-24T18:32:40.876Z,1758738760.875 [DAT](INFO): DAT read: Features enabled [Bearing]

2025-09-24T18:32:40.877Z,1758738760.877 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2025-09-24T18:32:40.877Z,1758738760.877 [DAT](INFO): commRate: 1200
2025-09-24T18:32:42.943Z,1758738762.943 [DAT](INFO): entering command mode
2025-09-24T18:32:43.144Z,1758738763.144 [DAT](INFO): DAT read: 

2025-09-24T18:32:43.144Z,1758738763.144 [DAT](INFO): DAT read: user:1>

2025-09-24T18:32:43.145Z,1758738763.145 [DAT](INFO): setting verbose to 3
2025-09-24T18:32:43.395Z,1758738763.395 [DAT](INFO): DAT read: user:1>

2025-09-24T18:32:43.396Z,1758738763.396 [DAT](INFO): DAT read: Verbose         | 3           

2025-09-24T18:32:43.397Z,1758738763.397 [DAT](INFO): set verbose to 3
2025-09-24T18:32:43.397Z,1758738763.397 [DAT](INFO): setting DatVerbose to 27440
2025-09-24T18:32:43.647Z,1758738763.647 [DAT](INFO): DAT read: user:2>

2025-09-24T18:32:43.648Z,1758738763.648 [DAT](INFO): DAT read: DatVerbose      | 27440       

2025-09-24T18:32:43.649Z,1758738763.649 [DAT](INFO): set DatVerbose to 27440
2025-09-24T18:32:43.649Z,1758738763.649 [DAT](INFO): setting transmit power to 8
2025-09-24T18:32:43.899Z,1758738763.899 [DAT](INFO): DAT read: user:3>

2025-09-24T18:32:43.900Z,1758738763.900 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2025-09-24T18:32:43.901Z,1758738763.901 [DAT](INFO): set transmit power to 8
2025-09-24T18:32:43.901Z,1758738763.901 [DAT](INFO): setting local address to 5
2025-09-24T18:32:43.908Z,1758738763.908 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:32:43.908Z,1758738763.908 [DVL_micro] Communications Fault, FailCount= 1
2025-09-24T18:32:43.908Z,1758738763.908 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:32:43.964Z,1758738763.964 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:32:44.151Z,1758738764.151 [DAT](INFO): DAT read: user:4>

2025-09-24T18:32:44.152Z,1758738764.152 [DAT](INFO): DAT read: LocalAddr       | 5           

2025-09-24T18:32:44.153Z,1758738764.153 [DAT](INFO): set local address to 5
2025-09-24T18:32:44.154Z,1758738764.154 [DAT](INFO): Setting time to: 18:32:44 And date to:9/24/2025
2025-09-24T18:32:44.403Z,1758738764.403 [DAT](INFO): DAT read: user:5>

2025-09-24T18:32:44.409Z,1758738764.409 [DAT](INFO): DAT read: Wed Sep 24, 2025  18:32:44  

2025-09-24T18:32:44.409Z,1758738764.409 [DAT](INFO): Local DAT time set to Wed Sep 24, 2025  18:32:44  

2025-09-24T18:32:44.443Z,1758738764.443 [DVL_micro](INFO): Powering down
2025-09-24T18:32:45.050Z,1758738765.050 [WetLabsBB2FL] Communications Fault, FailCount= 3
2025-09-24T18:32:45.050Z,1758738765.050 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:32:45.179Z,1758738765.179 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:32:45.179Z,1758738765.179 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:32:45.179Z,1758738765.179 [DVL_micro] No Fault, FailCount= 1
2025-09-24T18:32:45.547Z,1758738765.547 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:32:46.380Z,1758738766.380 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:32:46.380Z,1758738766.380 [WetLabsBB2FL] No Fault, FailCount= 3
2025-09-24T18:32:46.760Z,1758738766.760 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:32:52.054Z,1758738772.054 [WetLabsBB2FL] Communications Fault, FailCount= 4
2025-09-24T18:32:52.054Z,1758738772.054 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:32:52.462Z,1758738772.462 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:32:52.550Z,1758738772.550 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:32:53.679Z,1758738773.679 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:32:53.680Z,1758738773.680 [WetLabsBB2FL] No Fault, FailCount= 4
2025-09-24T18:32:53.791Z,1758738773.791 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:32:55.212Z,1758738775.212 [NAL9602](INFO): Powering up NAL9602
2025-09-24T18:32:59.054Z,1758738779.054 [WetLabsBB2FL] Communications Fault, FailCount= 5
2025-09-24T18:32:59.054Z,1758738779.054 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:32:59.322Z,1758738779.322 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:32:59.323Z,1758738779.323 [CBIT](FAULT): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:32:59.555Z,1758738779.555 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:33:02.889Z,1758738782.889 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:33:02.889Z,1758738782.889 [DVL_micro] Communications Fault, FailCount= 2
2025-09-24T18:33:02.889Z,1758738782.889 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:33:02.955Z,1758738782.955 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:33:03.395Z,1758738783.395 [DVL_micro](INFO): Powering down
2025-09-24T18:33:04.148Z,1758738784.148 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:33:04.148Z,1758738784.148 [DVL_micro] No Fault, FailCount= 2
2025-09-24T18:33:06.122Z,1758738786.122 [NAL9602](INFO): NAL9602 initialized
2025-09-24T18:33:21.877Z,1758738801.877 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:33:21.877Z,1758738801.877 [DVL_micro] Communications Fault, FailCount= 3
2025-09-24T18:33:21.877Z,1758738801.877 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:33:21.923Z,1758738801.923 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:33:21.924Z,1758738801.924 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2025-09-24T18:33:22.377Z,1758738802.377 [DVL_micro](INFO): Powering down
2025-09-24T18:33:22.425Z,1758738802.425 [CBIT](INFO): Critical error at 20250924T183321
2025-09-24T18:34:37.757Z,1758738877.757 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005051
2025-09-24T18:34:49.173Z,1758738889.173 [SBIT](IMPORTANT): Beginning Startup BIT
2025-09-24T18:34:49.178Z,1758738889.178 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-09-24T18:34:53.663Z,1758738893.663 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002502
CHAN A1 (24V): 0.005474
CHAN A2 (12V): -0.006367
CHAN A3 (5V): -0.005771
CHAN B0 (3.3V): -0.001311
CHAN B1 (3.15aV): -0.001359
CHAN B2 (3.15bV): -0.001453
CHAN B3 (GND): -0.001345
OPEN: 0.007101
Full Scale: +/- 1 mA
2025-09-24T18:35:26.007Z,1758738926.007 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-09-24T18:35:26.007Z,1758738926.007 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-09-24T18:35:26.164Z,1758738926.164 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-09-24T18:35:26.523Z,1758738926.523 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-09-24T18:35:26.524Z,1758738926.524 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-09-24T18:35:29.336Z,1758738929.336 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:35:29.336Z,1758738929.336 [WetLabsBB2FL] No Fault, FailCount= 5
2025-09-24T18:35:29.440Z,1758738929.440 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:35:34.730Z,1758738934.730 [WetLabsBB2FL] Communications Fault, FailCount= 1
2025-09-24T18:35:34.730Z,1758738934.730 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:35:34.911Z,1758738934.911 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:35:35.247Z,1758738935.247 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:35:36.136Z,1758738936.136 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:35:36.136Z,1758738936.136 [WetLabsBB2FL] No Fault, FailCount= 1
2025-09-24T18:35:36.476Z,1758738936.476 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:35:41.770Z,1758738941.770 [WetLabsBB2FL] Communications Fault, FailCount= 2
2025-09-24T18:35:41.770Z,1758738941.770 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:35:42.156Z,1758738942.156 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:35:42.271Z,1758738942.271 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:35:42.545Z,1758738942.545 [SBIT](IMPORTANT): SBIT PASSED
2025-09-24T18:35:42.545Z,1758738942.545 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-09-24T18:35:42.546Z,1758738942.546 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;

2025-09-24T18:35:42.546Z,1758738942.546 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=1 bool;

2025-09-24T18:35:42.547Z,1758738942.547 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere;

2025-09-24T18:35:42.547Z,1758738942.547 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;

2025-09-24T18:35:42.547Z,1758738942.547 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2025-09-24T18:35:42.547Z,1758738942.547 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=319.798725 cubic_centimeter;

2025-09-24T18:35:42.547Z,1758738942.547 [SBIT](IMPORTANT): VerticalControl.massDefault=30.833858 millimeter;

2025-09-24T18:35:42.939Z,1758738942.939 [MissionManager](IMPORTANT): Started mission Startup
2025-09-24T18:35:42.939Z,1758738942.939 [Startup] Running Loop=1
2025-09-24T18:35:42.940Z,1758738942.940 [Startup](DEBUG): Aggregate::initialize Startup
2025-09-24T18:35:42.940Z,1758738942.940 [Startup:A.GoToSurface] Running Loop=1
2025-09-24T18:35:42.940Z,1758738942.940 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-09-24T18:35:42.940Z,1758738942.940 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-09-24T18:35:42.941Z,1758738942.941 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-09-24T18:35:42.941Z,1758738942.941 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-09-24T18:35:42.941Z,1758738942.941 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-09-24T18:35:42.942Z,1758738942.942 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-09-24T18:35:42.942Z,1758738942.942 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-09-24T18:35:42.944Z,1758738942.944 [Startup:StartupSatComms] Running Loop=1
2025-09-24T18:35:42.944Z,1758738942.944 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-09-24T18:35:42.944Z,1758738942.944 [Startup:StartupSatComms:A] Running Loop=1
2025-09-24T18:35:43.335Z,1758738943.335 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-09-24T18:35:43.344Z,1758738943.344 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:35:43.344Z,1758738943.344 [WetLabsBB2FL] No Fault, FailCount= 2
2025-09-24T18:35:43.484Z,1758738943.484 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:35:48.779Z,1758738948.779 [WetLabsBB2FL] Communications Fault, FailCount= 3
2025-09-24T18:35:48.779Z,1758738948.779 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:35:49.007Z,1758738949.007 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:35:49.279Z,1758738949.279 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:35:50.213Z,1758738950.213 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:35:50.213Z,1758738950.213 [WetLabsBB2FL] No Fault, FailCount= 3
2025-09-24T18:35:50.492Z,1758738950.492 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:35:55.782Z,1758738955.782 [WetLabsBB2FL] Communications Fault, FailCount= 4
2025-09-24T18:35:55.782Z,1758738955.782 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:35:55.876Z,1758738955.876 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:35:56.283Z,1758738956.283 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:35:57.098Z,1758738957.098 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:35:57.098Z,1758738957.098 [WetLabsBB2FL] No Fault, FailCount= 4
2025-09-24T18:35:57.496Z,1758738957.496 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:36:02.793Z,1758738962.793 [WetLabsBB2FL] Communications Fault, FailCount= 5
2025-09-24T18:36:02.793Z,1758738962.793 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:36:03.167Z,1758738963.167 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:36:03.167Z,1758738963.167 [CBIT](FAULT): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:36:03.291Z,1758738963.291 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:36:22.135Z,1758738982.135 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:36:22.135Z,1758738982.135 [DVL_micro] No Fault, FailCount= 3
2025-09-24T18:36:27.632Z,1758738987.632 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 15 degree
2025-09-24T18:36:27.636Z,1758738987.636 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.elevatorAngleAction" handled in the control thread.
2025-09-24T18:36:27.792Z,1758738987.792 [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,Maintain_VerticalControl.elevatorAngleAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-09-24T18:36:39.175Z,1758738999.175 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction -15 degree
2025-09-24T18:36:39.884Z,1758738999.884 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:36:39.884Z,1758738999.884 [DVL_micro] Communications Fault, FailCount= 1
2025-09-24T18:36:39.884Z,1758738999.884 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:36:39.903Z,1758738999.903 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:36:40.379Z,1758739000.379 [DVL_micro](INFO): Powering down
2025-09-24T18:36:41.136Z,1758739001.136 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:36:41.136Z,1758739001.136 [DVL_micro] No Fault, FailCount= 1
2025-09-24T18:36:43.122Z,1758739003.122 [Startup:StartupSatComms:A](INFO): Timed out from 2025-09-24T18:35:42.9Z
2025-09-24T18:36:43.122Z,1758739003.122 [Startup:StartupSatComms:A] Stopped
2025-09-24T18:36:43.122Z,1758739003.122 [Startup:StartupSatComms:B] Running Loop=1
2025-09-24T18:36:43.553Z,1758739003.553 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-09-24T18:36:51.016Z,1758739011.016 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20250924T182543/Courier0004.lzma
2025-09-24T18:36:52.012Z,1758739012.012 [DataOverHttps](INFO): Moved sent file to Logs/20250924T182543/Courier0004.lzma.bak
2025-09-24T18:36:52.013Z,1758739012.013 [DataOverHttps](INFO): SBD MOMSN=26068905
2025-09-24T18:36:53.297Z,1758739013.297 [CommandExec](IMPORTANT): got command get platform_elevator_angle degree
2025-09-24T18:36:53.298Z,1758739013.298 [CommandExec](IMPORTANT): platform_elevator_angle -15.005007 arcdeg
2025-09-24T18:36:58.870Z,1758739018.870 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:36:58.870Z,1758739018.870 [DVL_micro] Communications Fault, FailCount= 2
2025-09-24T18:36:58.870Z,1758739018.870 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:36:58.917Z,1758739018.917 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:36:59.375Z,1758739019.375 [DVL_micro](INFO): Powering down
2025-09-24T18:37:00.151Z,1758739020.151 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:37:00.151Z,1758739020.151 [DVL_micro] No Fault, FailCount= 2
2025-09-24T18:37:08.603Z,1758739028.603 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20250924T183214/Courier0000.lzma
2025-09-24T18:37:09.604Z,1758739029.604 [DataOverHttps](INFO): Moved sent file to Logs/20250924T183214/Courier0000.lzma.bak
2025-09-24T18:37:09.605Z,1758739029.605 [DataOverHttps](INFO): SBD MOMSN=26068908
2025-09-24T18:37:09.962Z,1758739029.962 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 15 degree
2025-09-24T18:37:17.859Z,1758739037.859 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:37:17.860Z,1758739037.860 [DVL_micro] Communications Fault, FailCount= 3
2025-09-24T18:37:17.860Z,1758739037.860 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:37:17.922Z,1758739037.922 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:37:17.935Z,1758739037.935 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2025-09-24T18:37:18.363Z,1758739038.363 [DVL_micro](INFO): Powering down
2025-09-24T18:37:18.383Z,1758739038.383 [CBIT](INFO): Critical error at 20250924T183717
2025-09-24T18:37:25.484Z,1758739045.484 [DataOverHttps](INFO): Sending 641 bytes from file Logs/20250924T182543/Express0005.lzma
2025-09-24T18:37:26.224Z,1758739046.224 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction -15 degree
2025-09-24T18:37:26.484Z,1758739046.484 [DataOverHttps](INFO): Moved sent file to Logs/20250924T182543/Express0005.lzma.bak
2025-09-24T18:37:26.485Z,1758739046.485 [DataOverHttps](INFO): SBD MOMSN=26068914
2025-09-24T18:37:30.219Z,1758739050.219 [CommandExec](IMPORTANT): got command configSet list
2025-09-24T18:37:30.219Z,1758739050.219 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-09-24T18:37:30.220Z,1758739050.220 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;

2025-09-24T18:37:30.224Z,1758739050.224 [CommandExec](IMPORTANT): CBIT.runNavErrorCritical=1 bool;

2025-09-24T18:37:30.225Z,1758739050.225 [CommandExec](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere;

2025-09-24T18:37:30.226Z,1758739050.226 [CommandExec](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;

2025-09-24T18:37:30.231Z,1758739050.231 [CommandExec](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2025-09-24T18:37:30.232Z,1758739050.232 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=319.798725 cubic_centimeter;

2025-09-24T18:37:30.233Z,1758739050.233 [CommandExec](IMPORTANT): VerticalControl.massDefault=30.833858 millimeter;

2025-09-24T18:37:42.545Z,1758739062.545 [DataOverHttps](INFO): Sending 1145 bytes from file Logs/20250924T183214/Express0001.lzma
2025-09-24T18:37:43.325Z,1758739063.325 [Startup:StartupSatComms:B](INFO): Timed out from 2025-09-24T18:36:43.1Z
2025-09-24T18:37:43.325Z,1758739063.325 [Startup:StartupSatComms:B] Stopped
2025-09-24T18:37:43.325Z,1758739063.325 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-09-24T18:37:43.325Z,1758739063.325 [Startup:StartupSatComms] Stopped
2025-09-24T18:37:43.325Z,1758739063.325 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-09-24T18:37:43.330Z,1758739063.330 [Startup](INFO): Completed Startup
2025-09-24T18:37:43.331Z,1758739063.331 [MissionManager](INFO): Startup is completed.
2025-09-24T18:37:43.331Z,1758739063.331 [MissionManager](INFO): Uninitializing Mission Startup
2025-09-24T18:37:43.331Z,1758739063.331 [Startup] Stopped
2025-09-24T18:37:43.331Z,1758739063.331 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-09-24T18:37:43.331Z,1758739063.331 [Startup:A.GoToSurface] Stopped
2025-09-24T18:37:43.331Z,1758739063.331 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-09-24T18:37:43.544Z,1758739063.544 [DataOverHttps](INFO): Moved sent file to Logs/20250924T183214/Express0001.lzma.bak
2025-09-24T18:37:43.544Z,1758739063.544 [DataOverHttps](INFO): SBD MOMSN=26068932
2025-09-24T18:37:43.732Z,1758739063.732 [MissionManager](IMPORTANT): Started mission Default
2025-09-24T18:37:43.732Z,1758739063.732 [Default] Running Loop=1
2025-09-24T18:37:43.732Z,1758739063.732 [Default](DEBUG): Aggregate::initialize Default
2025-09-24T18:37:43.732Z,1758739063.732 [Default:B.GoToSurface] Running Loop=1
2025-09-24T18:37:43.732Z,1758739063.732 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-09-24T18:37:43.733Z,1758739063.733 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-09-24T18:37:43.733Z,1758739063.733 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-09-24T18:37:43.733Z,1758739063.733 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-09-24T18:37:43.733Z,1758739063.733 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-09-24T18:37:43.734Z,1758739063.734 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-09-24T18:37:43.734Z,1758739063.734 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-09-24T18:37:43.755Z,1758739063.755 [Default:A.Wait] Running Loop=1
2025-09-24T18:37:43.755Z,1758739063.755 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-09-24T18:37:57.084Z,1758739077.084 [Default:A.Wait](INFO): Done Waiting.
2025-09-24T18:37:57.084Z,1758739077.084 [Default:A.Wait] Stopped
2025-09-24T18:37:57.084Z,1758739077.084 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-09-24T18:37:57.476Z,1758739077.476 [Default:CheckIn] Running Loop=1
2025-09-24T18:37:57.476Z,1758739077.476 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-09-24T18:37:57.476Z,1758739077.476 [Default:CheckIn:Read_GPS] Running Loop=1
2025-09-24T18:37:57.880Z,1758739077.880 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-09-24T18:38:09.585Z,1758739089.585 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-09-24T18:38:21.506Z,1758739101.506 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 15 degree
2025-09-24T18:38:22.129Z,1758739102.129 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-09-24T18:38:26.948Z,1758739106.948 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-09-24T18:38:26.948Z,1758739106.948 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-09-24T18:38:26.991Z,1758739106.991 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-09-24T18:38:27.407Z,1758739107.407 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-09-24T18:38:27.407Z,1758739107.407 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-09-24T18:38:33.018Z,1758739113.018 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:38:33.018Z,1758739113.018 [WetLabsBB2FL] No Fault, FailCount= 5
2025-09-24T18:38:33.177Z,1758739113.177 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:38:38.183Z,1758739118.183 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction -15 degree
2025-09-24T18:38:38.526Z,1758739118.526 [WetLabsBB2FL] Communications Fault, FailCount= 1
2025-09-24T18:38:38.526Z,1758739118.526 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:38:38.679Z,1758739118.679 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:38:39.027Z,1758739119.027 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:38:39.915Z,1758739119.915 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:38:39.915Z,1758739119.915 [WetLabsBB2FL] No Fault, FailCount= 1
2025-09-24T18:38:40.240Z,1758739120.240 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:38:45.536Z,1758739125.536 [WetLabsBB2FL] Communications Fault, FailCount= 2
2025-09-24T18:38:45.536Z,1758739125.536 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:38:45.700Z,1758739125.700 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:38:46.038Z,1758739126.038 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:38:46.931Z,1758739126.931 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:38:46.931Z,1758739126.931 [WetLabsBB2FL] No Fault, FailCount= 2
2025-09-24T18:38:47.253Z,1758739127.253 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:38:52.542Z,1758739132.542 [WetLabsBB2FL] Communications Fault, FailCount= 3
2025-09-24T18:38:52.542Z,1758739132.542 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:38:52.690Z,1758739132.690 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 15 degree
2025-09-24T18:38:52.845Z,1758739132.845 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:38:53.043Z,1758739133.043 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:38:54.163Z,1758739134.163 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:38:54.163Z,1758739134.163 [WetLabsBB2FL] No Fault, FailCount= 3
2025-09-24T18:38:54.256Z,1758739134.256 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:38:58.895Z,1758739138.895 [ElevatorServo](FAULT): Overload Error
2025-09-24T18:38:58.895Z,1758739138.895 [ElevatorServo] Hardware Fault, FailCount= 1
2025-09-24T18:38:58.895Z,1758739138.895 [ElevatorServo](ERROR): Hardware Fault
2025-09-24T18:38:59.023Z,1758739139.023 [CBIT](ERROR): Hardware Fault in component: ElevatorServo
2025-09-24T18:38:59.280Z,1758739139.280 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-09-24T18:38:59.280Z,1758739139.280 [ElevatorServo](INFO): Powering down
2025-09-24T18:38:59.546Z,1758739139.546 [WetLabsBB2FL] Communications Fault, FailCount= 4
2025-09-24T18:38:59.546Z,1758739139.546 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:38:59.713Z,1758739139.713 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:39:00.047Z,1758739140.047 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:39:00.117Z,1758739140.117 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-09-24T18:39:00.231Z,1758739140.231 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-09-24T18:39:00.235Z,1758739140.235 [CBIT](INFO): Clearing failed state for component ElevatorServo
2025-09-24T18:39:00.236Z,1758739140.236 [ElevatorServo] No Fault, FailCount= 1
2025-09-24T18:39:00.910Z,1758739140.910 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:39:00.910Z,1758739140.910 [WetLabsBB2FL] No Fault, FailCount= 4
2025-09-24T18:39:01.260Z,1758739141.260 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:39:06.557Z,1758739146.557 [WetLabsBB2FL] Communications Fault, FailCount= 5
2025-09-24T18:39:06.557Z,1758739146.557 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:39:06.573Z,1758739146.573 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:39:06.573Z,1758739146.573 [CBIT](FAULT): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:39:07.055Z,1758739147.055 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:39:50.838Z,1758739190.838 [CommandExec](IMPORTANT): got command configSet ElevatorServo.currLimit 25 percent persist
2025-09-24T18:40:04.570Z,1758739204.570 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction -15 degree
2025-09-24T18:40:18.248Z,1758739218.248 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:40:18.248Z,1758739218.248 [DVL_micro] No Fault, FailCount= 3
2025-09-24T18:40:27.996Z,1758739227.996 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction 15 degree
2025-09-24T18:40:35.849Z,1758739235.849 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:40:35.849Z,1758739235.849 [DVL_micro] Communications Fault, FailCount= 1
2025-09-24T18:40:35.849Z,1758739235.849 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:40:35.913Z,1758739235.913 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:40:36.347Z,1758739236.347 [DVL_micro](INFO): Powering down
2025-09-24T18:40:37.096Z,1758739237.096 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:40:37.096Z,1758739237.096 [DVL_micro] No Fault, FailCount= 1
2025-09-24T18:40:54.840Z,1758739254.840 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:40:54.840Z,1758739254.840 [DVL_micro] Communications Fault, FailCount= 2
2025-09-24T18:40:54.840Z,1758739254.840 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:40:54.923Z,1758739254.923 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:40:55.339Z,1758739255.339 [DVL_micro](INFO): Powering down
2025-09-24T18:40:56.080Z,1758739256.080 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:40:56.080Z,1758739256.080 [DVL_micro] No Fault, FailCount= 2
2025-09-24T18:41:13.890Z,1758739273.890 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:41:13.890Z,1758739273.890 [DVL_micro] Communications Fault, FailCount= 3
2025-09-24T18:41:13.890Z,1758739273.890 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:41:13.948Z,1758739273.948 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:41:13.949Z,1758739273.949 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2025-09-24T18:41:14.355Z,1758739274.355 [DVL_micro](INFO): Powering down
2025-09-24T18:41:14.408Z,1758739274.408 [CBIT](INFO): Critical error at 20250924T184113
2025-09-24T18:41:27.980Z,1758739287.980 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-09-24T18:41:27.980Z,1758739287.980 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-09-24T18:41:28.011Z,1758739288.011 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-09-24T18:41:28.431Z,1758739288.431 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-09-24T18:41:28.431Z,1758739288.431 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-09-24T18:41:36.931Z,1758739296.931 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:41:36.931Z,1758739296.931 [WetLabsBB2FL] No Fault, FailCount= 5
2025-09-24T18:41:37.008Z,1758739297.008 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:41:42.303Z,1758739302.303 [WetLabsBB2FL] Communications Fault, FailCount= 1
2025-09-24T18:41:42.303Z,1758739302.303 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:41:42.556Z,1758739302.556 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:41:42.803Z,1758739302.803 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:41:43.755Z,1758739303.755 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:41:43.755Z,1758739303.755 [WetLabsBB2FL] No Fault, FailCount= 1
2025-09-24T18:41:44.016Z,1758739304.016 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:41:49.311Z,1758739309.311 [WetLabsBB2FL] Communications Fault, FailCount= 2
2025-09-24T18:41:49.311Z,1758739309.311 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:41:49.404Z,1758739309.404 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:41:49.811Z,1758739309.811 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:41:50.686Z,1758739310.686 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:41:50.686Z,1758739310.686 [WetLabsBB2FL] No Fault, FailCount= 2
2025-09-24T18:41:51.024Z,1758739311.024 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:41:56.322Z,1758739316.322 [WetLabsBB2FL] Communications Fault, FailCount= 3
2025-09-24T18:41:56.322Z,1758739316.322 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:41:56.676Z,1758739316.676 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:41:56.823Z,1758739316.823 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:41:57.897Z,1758739317.897 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:41:57.897Z,1758739317.897 [WetLabsBB2FL] No Fault, FailCount= 3
2025-09-24T18:41:58.036Z,1758739318.036 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:42:03.330Z,1758739323.330 [WetLabsBB2FL] Communications Fault, FailCount= 4
2025-09-24T18:42:03.330Z,1758739323.330 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:42:03.552Z,1758739323.552 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:42:03.831Z,1758739323.831 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:42:04.770Z,1758739324.770 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:42:04.771Z,1758739324.771 [WetLabsBB2FL] No Fault, FailCount= 4
2025-09-24T18:42:05.045Z,1758739325.045 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:42:10.334Z,1758739330.334 [WetLabsBB2FL] Communications Fault, FailCount= 5
2025-09-24T18:42:10.334Z,1758739330.334 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:42:10.429Z,1758739330.429 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:42:10.429Z,1758739330.429 [CBIT](FAULT): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:42:10.839Z,1758739330.839 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:42:57.727Z,1758739377.727 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-09-24T18:37:57.5Z
2025-09-24T18:42:57.727Z,1758739377.727 [Default:CheckIn:Read_GPS] Stopped
2025-09-24T18:42:57.727Z,1758739377.727 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-09-24T18:42:58.088Z,1758739378.088 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-09-24T18:43:05.834Z,1758739385.834 [DataOverHttps](INFO): Sending 100 bytes from file Logs/20250924T183214/Courier0004.lzma
2025-09-24T18:43:06.836Z,1758739386.836 [DataOverHttps](INFO): Moved sent file to Logs/20250924T183214/Courier0004.lzma.bak
2025-09-24T18:43:06.836Z,1758739386.836 [DataOverHttps](INFO): SBD MOMSN=26068963
2025-09-24T18:43:08.561Z,1758739388.561 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-09-24T18:43:08.561Z,1758739388.561 [NAL9602] Data Fault, FailCount= 1
2025-09-24T18:43:08.561Z,1758739388.561 [NAL9602](ERROR): Data Fault
2025-09-24T18:43:08.584Z,1758739388.584 [CBIT](ERROR): Data Fault in component: NAL9602
2025-09-24T18:43:08.969Z,1758739388.969 [NAL9602](INFO): Powering down
2025-09-24T18:43:09.808Z,1758739389.808 [CBIT](INFO): Clearing failed state for component NAL9602
2025-09-24T18:43:09.809Z,1758739389.809 [NAL9602] No Fault, FailCount= 1
2025-09-24T18:43:22.568Z,1758739402.568 [DataOverHttps](INFO): Sending 808 bytes from file Logs/20250924T183214/Express0005.lzma
2025-09-24T18:43:23.568Z,1758739403.568 [DataOverHttps](INFO): Moved sent file to Logs/20250924T183214/Express0005.lzma.bak
2025-09-24T18:43:23.568Z,1758739403.568 [DataOverHttps](INFO): SBD MOMSN=26068967
2025-09-24T18:43:25.140Z,1758739405.140 [Default:CheckIn:Read_Iridium] Stopped
2025-09-24T18:43:25.140Z,1758739405.140 [Default:CheckIn:C.Wait] Running Loop=1
2025-09-24T18:43:25.140Z,1758739405.140 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-09-24T18:43:39.268Z,1758739419.268 [NAL9602](INFO): Powering up NAL9602
2025-09-24T18:43:50.170Z,1758739430.170 [NAL9602](INFO): NAL9602 initialized
2025-09-24T18:44:02.596Z,1758739442.596 [DataOverHttps](IMPORTANT): SBD MTMSN=20250924T184402
2025-09-24T18:44:09.943Z,1758739449.943 [DataOverHttps](INFO): Received command: run Deprecated/Demo/openhouseBenchDemo.xml
2025-09-24T18:44:10.093Z,1758739450.093 [CommandExec](IMPORTANT): got command run ./Missions/Deprecated/Demo/openhouseBenchDemo.xml
2025-09-24T18:44:10.093Z,1758739450.093 [MissionManager](INFO): Loading Mission from file: ./Missions/Deprecated/Demo/openhouseBenchDemo.xml
2025-09-24T18:44:10.143Z,1758739450.143 [openhouseBenchDemo:A_Timeout:A.StopMission](DEBUG): Construct StopMission.
2025-09-24T18:44:10.144Z,1758739450.144 [openhouseBenchDemo:A.Buoyancy](DEBUG): Construct Buoyancy.
2025-09-24T18:44:10.150Z,1758739450.150 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Construct.
2025-09-24T18:44:10.153Z,1758739450.153 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Construct.
2025-09-24T18:44:10.161Z,1758739450.161 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Construct.
2025-09-24T18:44:10.169Z,1758739450.169 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Construct Wait.
2025-09-24T18:44:10.172Z,1758739450.172 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Construct.
2025-09-24T18:44:10.192Z,1758739450.192 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Construct.
2025-09-24T18:44:10.208Z,1758739450.208 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Construct.
2025-09-24T18:44:10.223Z,1758739450.223 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Construct Wait.
2025-09-24T18:44:10.231Z,1758739450.231 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!--
-   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 xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="openhouseBenchDemo">

    <Timeout Duration="P600M">
        <Guidance:StopMission>
            <Sequence/>
        </Guidance:StopMission>
    </Timeout>

    <Guidance:Buoyancy>
        <Progression/>
        <Setting><Guidance:Buoyancy.position/><Units:cubic_centimeter/><Value>945</Value></Setting>
    </Guidance:Buoyancy>

    <Aggregate Id="MAIN">

        <Sequence Repeat="700"/>

        <Aggregate Id="positiveActuation">

            <Sequence/>

            <Guidance:SetSpeed>
                <Parallel/>
                <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>1</Value></Setting>
            </Guidance:SetSpeed>

            <Guidance:Pitch>
                <Parallel/>
                <Setting><Guidance:Pitch.elevatorAngle/><Units:degree/><Value>13</Value></Setting>
                <Setting><Guidance:Pitch.depth/><Units:meter/><Value>0</Value></Setting>
            </Guidance:Pitch>

            <Guidance:Point>
                <Parallel/>
                <Setting><Guidance:Point.rudderAngle/><Units:degree/><Value>13</Value></Setting>
            </Guidance:Point>

            <Guidance:Wait>
                <Sequence/>
                <Timeout Duration="P10S"></Timeout>
            </Guidance:Wait>

        </Aggregate>

        <Aggregate Id="negativeActuation">

            <Sequence/>

            <Guidance:SetSpeed>
                <Parallel/>
                <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0.5</Value></Setting>
            </Guidance:SetSpeed>

            <Guidance:Pitch>
                <Parallel/>
                <Setting><Guidance:Pitch.elevatorAngle/><Units:degree/><Value>-13</Value></Setting>
                <Setting><Guidance:Pitch.depth/><Units:meter/><Value>0</Value></Setting>
            </Guidance:Pitch>

            <Guidance:Point>
                <Parallel/>
                <Setting><Guidance:Point.rudderAngle/><Units:degree/><Value>-13</Value></Setting>
            </Guidance:Point>

            <Guidance:Wait>
                <Sequence/>
                <Timeout Duration="P10S"></Timeout>
            </Guidance:Wait>

        </Aggregate>

    </Aggregate>

</Mission>


2025-09-24T18:44:10.233Z,1758739450.233 [CommandExec](IMPORTANT): Running ./Missions/Deprecated/Demo/openhouseBenchDemo.xml
2025-09-24T18:44:10.408Z,1758739450.408 [Default] Stopped
2025-09-24T18:44:10.408Z,1758739450.408 [Default](DEBUG): Aggregate::uninitialize Default
2025-09-24T18:44:10.408Z,1758739450.408 [Default:B.GoToSurface] Stopped
2025-09-24T18:44:10.408Z,1758739450.408 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-09-24T18:44:10.408Z,1758739450.408 [Default:CheckIn] Stopped
2025-09-24T18:44:10.408Z,1758739450.408 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-09-24T18:44:10.408Z,1758739450.408 [Default:CheckIn:C.Wait] Stopped
2025-09-24T18:44:10.408Z,1758739450.408 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-09-24T18:44:10.408Z,1758739450.408 [MissionManager](IMPORTANT): Started mission openhouseBenchDemo
2025-09-24T18:44:10.409Z,1758739450.409 [openhouseBenchDemo] Running Loop=1
2025-09-24T18:44:10.409Z,1758739450.409 [openhouseBenchDemo](DEBUG): Aggregate::initialize openhouseBenchDemo
2025-09-24T18:44:10.409Z,1758739450.409 [openhouseBenchDemo:A.Buoyancy] Running Loop=1
2025-09-24T18:44:10.409Z,1758739450.409 [openhouseBenchDemo:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-09-24T18:44:10.410Z,1758739450.410 [openhouseBenchDemo:MAIN] Running Loop=1
2025-09-24T18:44:10.410Z,1758739450.410 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-09-24T18:44:10.410Z,1758739450.410 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-09-24T18:44:10.410Z,1758739450.410 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-09-24T18:44:10.411Z,1758739450.411 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-09-24T18:44:10.411Z,1758739450.411 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-09-24T18:44:10.411Z,1758739450.411 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-09-24T18:44:10.411Z,1758739450.411 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-09-24T18:44:10.411Z,1758739450.411 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-09-24T18:44:10.412Z,1758739450.412 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-09-24T18:44:10.412Z,1758739450.412 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-09-24T18:44:10.412Z,1758739450.412 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-09-24T18:44:10.865Z,1758739450.865 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-09-24T18:44:10.866Z,1758739450.866 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-09-24T18:44:10.867Z,1758739450.867 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-09-24T18:44:14.102Z,1758739454.102 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:44:14.103Z,1758739454.103 [DVL_micro] No Fault, FailCount= 3
2025-09-24T18:44:20.532Z,1758739460.532 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-09-24T18:44:10.4Z
2025-09-24T18:44:20.532Z,1758739460.532 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-09-24T18:44:20.532Z,1758739460.532 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-09-24T18:44:20.534Z,1758739460.534 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-09-24T18:44:20.535Z,1758739460.535 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-09-24T18:44:20.931Z,1758739460.931 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-09-24T18:44:20.932Z,1758739460.932 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-09-24T18:44:20.932Z,1758739460.932 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-09-24T18:44:28.992Z,1758739468.992 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-09-24T18:44:28.992Z,1758739468.992 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-09-24T18:44:29.106Z,1758739469.106 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-09-24T18:44:29.470Z,1758739469.470 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-09-24T18:44:29.470Z,1758739469.470 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-09-24T18:44:30.632Z,1758739470.632 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-09-24T18:44:20.5Z
2025-09-24T18:44:30.633Z,1758739470.633 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-09-24T18:44:30.633Z,1758739470.633 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-09-24T18:44:30.634Z,1758739470.634 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-09-24T18:44:30.634Z,1758739470.634 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-09-24T18:44:30.634Z,1758739470.634 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-09-24T18:44:30.634Z,1758739470.634 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-09-24T18:44:30.634Z,1758739470.634 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-09-24T18:44:30.634Z,1758739470.634 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-09-24T18:44:30.634Z,1758739470.634 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN] Stopped
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN](INFO): Running loop #2
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN] Running Loop=2
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-09-24T18:44:30.635Z,1758739470.635 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-09-24T18:44:30.636Z,1758739470.636 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-09-24T18:44:30.636Z,1758739470.636 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-09-24T18:44:30.636Z,1758739470.636 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-09-24T18:44:30.636Z,1758739470.636 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-09-24T18:44:30.636Z,1758739470.636 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-09-24T18:44:30.636Z,1758739470.636 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-09-24T18:44:31.814Z,1758739471.814 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:44:31.814Z,1758739471.814 [DVL_micro] Communications Fault, FailCount= 1
2025-09-24T18:44:31.814Z,1758739471.814 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:44:31.922Z,1758739471.922 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:44:32.311Z,1758739472.311 [DVL_micro](INFO): Powering down
2025-09-24T18:44:33.154Z,1758739473.154 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:44:33.154Z,1758739473.154 [DVL_micro] No Fault, FailCount= 1
2025-09-24T18:44:35.767Z,1758739475.767 [CommandExec](IMPORTANT): got command stop
2025-09-24T18:44:35.767Z,1758739475.767 [CommandExec](IMPORTANT): Scheduling is paused
2025-09-24T18:44:35.767Z,1758739475.767 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-09-24T18:44:35.895Z,1758739475.895 [MissionManager](INFO): MissionManager is completed.
2025-09-24T18:44:35.895Z,1758739475.895 [MissionManager](INFO): Uninitializing Mission openhouseBenchDemo
2025-09-24T18:44:35.895Z,1758739475.895 [openhouseBenchDemo] Stopped
2025-09-24T18:44:35.895Z,1758739475.895 [openhouseBenchDemo](DEBUG): Aggregate::uninitialize openhouseBenchDemo
2025-09-24T18:44:35.895Z,1758739475.895 [openhouseBenchDemo:A.Buoyancy] Stopped
2025-09-24T18:44:35.895Z,1758739475.895 [openhouseBenchDemo:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-09-24T18:44:35.895Z,1758739475.895 [openhouseBenchDemo:MAIN] Stopped
2025-09-24T18:44:35.895Z,1758739475.895 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-09-24T18:44:35.896Z,1758739475.896 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-09-24T18:44:36.311Z,1758739476.311 [MissionManager](IMPORTANT): Started mission Default
2025-09-24T18:44:36.311Z,1758739476.311 [Default] Running Loop=1
2025-09-24T18:44:36.311Z,1758739476.311 [Default](DEBUG): Aggregate::initialize Default
2025-09-24T18:44:36.311Z,1758739476.311 [Default:B.GoToSurface] Running Loop=1
2025-09-24T18:44:36.311Z,1758739476.311 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-09-24T18:44:36.312Z,1758739476.312 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-09-24T18:44:36.312Z,1758739476.312 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-09-24T18:44:36.312Z,1758739476.312 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-09-24T18:44:36.312Z,1758739476.312 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-09-24T18:44:36.313Z,1758739476.313 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-09-24T18:44:36.313Z,1758739476.313 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-09-24T18:44:36.313Z,1758739476.313 [Default:A.Wait] Running Loop=1
2025-09-24T18:44:36.313Z,1758739476.313 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-09-24T18:44:40.463Z,1758739480.463 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:44:40.463Z,1758739480.463 [WetLabsBB2FL] No Fault, FailCount= 5
2025-09-24T18:44:40.800Z,1758739480.800 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:44:46.098Z,1758739486.098 [WetLabsBB2FL] Communications Fault, FailCount= 1
2025-09-24T18:44:46.098Z,1758739486.098 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:44:46.391Z,1758739486.391 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:44:46.599Z,1758739486.599 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:44:47.690Z,1758739487.690 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:44:47.690Z,1758739487.690 [WetLabsBB2FL] No Fault, FailCount= 1
2025-09-24T18:44:47.812Z,1758739487.812 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:44:49.649Z,1758739489.649 [Default:A.Wait](INFO): Done Waiting.
2025-09-24T18:44:49.649Z,1758739489.649 [Default:A.Wait] Stopped
2025-09-24T18:44:49.649Z,1758739489.649 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-09-24T18:44:50.035Z,1758739490.035 [Default:CheckIn] Running Loop=1
2025-09-24T18:44:50.035Z,1758739490.035 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-09-24T18:44:50.035Z,1758739490.035 [Default:CheckIn:Read_GPS] Running Loop=1
2025-09-24T18:44:50.823Z,1758739490.823 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:44:50.824Z,1758739490.824 [DVL_micro] Communications Fault, FailCount= 2
2025-09-24T18:44:50.824Z,1758739490.824 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:44:50.896Z,1758739490.896 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:44:51.299Z,1758739491.299 [DVL_micro](INFO): Powering down
2025-09-24T18:44:52.027Z,1758739492.027 [CBIT](INFO): Clearing failed state for component DVL_micro
2025-09-24T18:44:52.027Z,1758739492.027 [DVL_micro] No Fault, FailCount= 2
2025-09-24T18:44:53.122Z,1758739493.122 [WetLabsBB2FL] Communications Fault, FailCount= 2
2025-09-24T18:44:53.122Z,1758739493.122 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:44:53.317Z,1758739493.317 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:44:53.625Z,1758739493.625 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:44:54.470Z,1758739494.470 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:44:54.470Z,1758739494.470 [WetLabsBB2FL] No Fault, FailCount= 2
2025-09-24T18:44:54.836Z,1758739494.836 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:45:00.130Z,1758739500.130 [WetLabsBB2FL] Communications Fault, FailCount= 3
2025-09-24T18:45:00.130Z,1758739500.130 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:45:00.565Z,1758739500.565 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:45:00.635Z,1758739500.635 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:45:01.744Z,1758739501.744 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:45:01.744Z,1758739501.744 [WetLabsBB2FL] No Fault, FailCount= 3
2025-09-24T18:45:01.848Z,1758739501.848 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:45:07.142Z,1758739507.142 [WetLabsBB2FL] Communications Fault, FailCount= 4
2025-09-24T18:45:07.142Z,1758739507.142 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:45:07.417Z,1758739507.417 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:45:07.643Z,1758739507.643 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:45:08.617Z,1758739508.617 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2025-09-24T18:45:08.617Z,1758739508.617 [WetLabsBB2FL] No Fault, FailCount= 4
2025-09-24T18:45:08.857Z,1758739508.857 [WetLabsBB2FL](INFO): Powering up
2025-09-24T18:45:09.784Z,1758739509.784 [DVL_micro](FAULT): Failed to initialize within timeout.
2025-09-24T18:45:09.784Z,1758739509.784 [DVL_micro] Communications Fault, FailCount= 3
2025-09-24T18:45:09.784Z,1758739509.784 [DVL_micro](ERROR): Communications Fault
2025-09-24T18:45:09.886Z,1758739509.886 [CBIT](ERROR): Communications Fault in component: DVL_micro
2025-09-24T18:45:09.886Z,1758739509.886 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2025-09-24T18:45:10.298Z,1758739510.298 [DVL_micro](INFO): Powering down
2025-09-24T18:45:10.386Z,1758739510.386 [CommandExec](FAULT): Scheduling is paused
2025-09-24T18:45:10.391Z,1758739510.391 [CBIT](INFO): Critical error at 20250924T184509
2025-09-24T18:45:14.146Z,1758739514.146 [WetLabsBB2FL] Communications Fault, FailCount= 5
2025-09-24T18:45:14.147Z,1758739514.147 [WetLabsBB2FL](ERROR): Communications Fault
2025-09-24T18:45:14.301Z,1758739514.301 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:45:14.301Z,1758739514.301 [CBIT](FAULT): Communications Fault in component: WetLabsBB2FL
2025-09-24T18:45:14.659Z,1758739514.659 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:45:17.296Z,1758739517.296 [CommandExec](IMPORTANT): got command configSet DVL_micro.loadAtStartup 0 bool persist
2025-09-24T18:45:17.297Z,1758739517.297 [CommandExec](IMPORTANT): configSet DVL_micro.loadAtStartup requires a restart to take effect.
2025-09-24T18:45:17.299Z,1758739517.299 [CommandExec](IMPORTANT): got command configSet WetLabsBB2FL.loadAtStartup 0 bool persist
2025-09-24T18:45:17.300Z,1758739517.300 [CommandExec](IMPORTANT): configSet WetLabsBB2FL.loadAtStartup requires a restart to take effect.
2025-09-24T18:45:17.302Z,1758739517.302 [CommandExec](IMPORTANT): got command restart application
2025-09-24T18:45:18.307Z,1758739518.307 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:18.307Z,1758739518.307 [CommandExec](INFO): Uninitializing the command executive.
2025-09-24T18:45:18.307Z,1758739518.307 [CommandExec](INFO): Uninitializing the command scheduler.
2025-09-24T18:45:18.307Z,1758739518.307 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:18.362Z,1758739518.362 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2025-09-24T18:45:18.363Z,1758739518.363 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-09-24T18:45:18.363Z,1758739518.363 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:18.364Z,1758739518.364 [NavChartDb](INFO): Join timeout helper Thread ID is 6376
2025-09-24T18:45:18.411Z,1758739518.411 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:18.411Z,1758739518.411 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:18.422Z,1758739518.422 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-09-24T18:45:18.422Z,1758739518.422 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:18.423Z,1758739518.423 [Radio_Surface](INFO): Join timeout helper Thread ID is 6377
2025-09-24T18:45:18.819Z,1758739518.819 [Radio_Surface](INFO): Powering down
2025-09-24T18:45:18.819Z,1758739518.819 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:18.820Z,1758739518.820 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:18.827Z,1758739518.827 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-09-24T18:45:18.827Z,1758739518.827 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:18.828Z,1758739518.828 [Onboard](INFO): Join timeout helper Thread ID is 6378
2025-09-24T18:45:19.791Z,1758739519.791 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-09-24T18:45:21.431Z,1758739521.431 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:21.431Z,1758739521.431 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:21.446Z,1758739521.446 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-09-24T18:45:21.446Z,1758739521.446 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:21.447Z,1758739521.447 [DataOverHttps](INFO): Join timeout helper Thread ID is 6379
2025-09-24T18:45:21.799Z,1758739521.799 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:21.799Z,1758739521.799 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:21.802Z,1758739521.802 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2025-09-24T18:45:21.802Z,1758739521.802 [DAT ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:21.803Z,1758739521.803 [DAT](INFO): Join timeout helper Thread ID is 6380
2025-09-24T18:45:21.966Z,1758739521.966 [DAT](INFO): Powering down
2025-09-24T18:45:22.039Z,1758739522.039 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:22.039Z,1758739522.039 [DAT](INFO): Powering down
2025-09-24T18:45:22.040Z,1758739522.040 [DAT ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:22.047Z,1758739522.047 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2025-09-24T18:45:22.047Z,1758739522.047 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:22.048Z,1758739522.048 [BackseatComponent](INFO): Join timeout helper Thread ID is 6381
2025-09-24T18:45:22.135Z,1758739522.135 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:22.135Z,1758739522.135 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:22.147Z,1758739522.147 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2025-09-24T18:45:22.147Z,1758739522.147 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:22.148Z,1758739522.148 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6382
2025-09-24T18:45:22.342Z,1758739522.342 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:22.343Z,1758739522.343 [WetLabsBB2FL](INFO): Powering down
2025-09-24T18:45:22.343Z,1758739522.343 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:22.347Z,1758739522.347 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2025-09-24T18:45:22.347Z,1758739522.347 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:22.348Z,1758739522.348 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6383
2025-09-24T18:45:22.963Z,1758739522.963 [CTD_Seabird](INFO): Powering down
2025-09-24T18:45:22.983Z,1758739522.983 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:22.984Z,1758739522.984 [CTD_Seabird](INFO): Powering down
2025-09-24T18:45:22.998Z,1758739522.998 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.003Z,1758739523.003 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2025-09-24T18:45:23.003Z,1758739523.003 [logger ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.004Z,1758739523.004 [logger](INFO): Join timeout helper Thread ID is 6384
2025-09-24T18:45:23.023Z,1758739523.023 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:23.023Z,1758739523.023 [logger ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.043Z,1758739523.043 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2025-09-24T18:45:23.043Z,1758739523.043 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.044Z,1758739523.044 [CommandLine](INFO): Join timeout helper Thread ID is 6385
2025-09-24T18:45:23.119Z,1758739523.119 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:23.119Z,1758739523.119 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.135Z,1758739523.135 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2025-09-24T18:45:23.135Z,1758739523.135 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.136Z,1758739523.136 [CommandExec](INFO): Join timeout helper Thread ID is 6386
2025-09-24T18:45:23.139Z,1758739523.139 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2025-09-24T18:45:23.139Z,1758739523.139 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.140Z,1758739523.140 [controlThread](INFO): Join timeout helper Thread ID is 6387
2025-09-24T18:45:23.503Z,1758739523.503 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2025-09-24T18:45:23.503Z,1758739523.503 [controlThread](DEBUG): Uninitializing ControlThread
2025-09-24T18:45:23.503Z,1758739523.503 [AHRS_M2](INFO): Powering down
2025-09-24T18:45:23.583Z,1758739523.583 [DVL_micro](INFO): Powering down
2025-09-24T18:45:23.584Z,1758739523.584 [NAL9602](INFO): Powering down
2025-09-24T18:45:23.585Z,1758739523.585 [Sonardyne_Nano](INFO): Powering down
2025-09-24T18:45:23.791Z,1758739523.791 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2025-09-24T18:45:23.791Z,1758739523.791 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2025-09-24T18:45:23.792Z,1758739523.792 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2025-09-24T18:45:23.792Z,1758739523.792 [MissionManager](INFO): Uninitializing Mission Default
2025-09-24T18:45:23.792Z,1758739523.792 [Default] Stopped
2025-09-24T18:45:23.793Z,1758739523.793 [Default](DEBUG): Aggregate::uninitialize Default
2025-09-24T18:45:23.793Z,1758739523.793 [Default:B.GoToSurface] Stopped
2025-09-24T18:45:23.793Z,1758739523.793 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-09-24T18:45:23.793Z,1758739523.793 [Default:CheckIn] Stopped
2025-09-24T18:45:23.793Z,1758739523.793 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-09-24T18:45:23.793Z,1758739523.793 [Default:CheckIn:Read_GPS] Stopped
2025-09-24T18:45:23.796Z,1758739523.796 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2025-09-24T18:45:23.796Z,1758739523.796 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2025-09-24T18:45:23.796Z,1758739523.796 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2025-09-24T18:45:23.797Z,1758739523.797 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2025-09-24T18:45:23.797Z,1758739523.797 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-09-24T18:45:23.797Z,1758739523.797 [BuoyancyServo](INFO): Powering down
2025-09-24T18:45:23.810Z,1758739523.810 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-09-24T18:45:23.811Z,1758739523.811 [ElevatorServo](INFO): Powering down
2025-09-24T18:45:23.811Z,1758739523.811 [MassServo](DEBUG): Uninitialize Mass Servo.
2025-09-24T18:45:23.811Z,1758739523.811 [MassServo](INFO): Powering down
2025-09-24T18:45:23.812Z,1758739523.812 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2025-09-24T18:45:23.812Z,1758739523.812 [RudderServo](INFO): Powering down
2025-09-24T18:45:23.813Z,1758739523.813 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-09-24T18:45:23.813Z,1758739523.813 [ThrusterHE](INFO): Powering down
2025-09-24T18:45:23.814Z,1758739523.814 [SBIT](DEBUG): Uninitialize SBIT Component.
2025-09-24T18:45:23.815Z,1758739523.815 [IBIT](DEBUG): Uninitialize IBIT Component.
2025-09-24T18:45:23.815Z,1758739523.815 [CBIT](DEBUG): Uninitialize CBIT Component.
2025-09-24T18:45:23.815Z,1758739523.815 [CBIT](DEBUG): Powering off loads.
2025-09-24T18:45:23.826Z,1758739523.826 [CBIT](DEBUG): Disabling WDT.
2025-09-24T18:45:23.838Z,1758739523.838 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-09-24T18:45:23.839Z,1758739523.839 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-09-24T18:45:23.840Z,1758739523.840 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.861Z,1758739523.861 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-09-24T18:45:23.861Z,1758739523.861 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-09-24T18:45:23.875Z,1758739523.875 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.882Z,1758739523.882 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.913Z,1758739523.913 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.916Z,1758739523.916 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.924Z,1758739523.924 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.930Z,1758739523.930 [DAT ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:23.971Z,1758739523.971 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:24.026Z,1758739524.026 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-09-24T18:45:24.091Z,1758739524.091 [logger ThreadHandler](INFO): Thread cancelled.