2025-03-04T20:36:04.558Z,1741120564.558 [Supervisor](DEBUG): Initializing supervisor.
2025-03-04T20:36:04.562Z,1741120564.562 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-03-04T20:36:04.563Z,1741120564.563 [SyncHandler](INFO): Protected caller Thread ID is 9036
2025-03-04T20:36:04.563Z,1741120564.563 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-03-04T20:36:04.564Z,1741120564.564 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-03-04T20:36:04.564Z,1741120564.564 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9037
2025-03-04T20:36:04.568Z,1741120564.568 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-03-04T20:36:04.585Z,1741120564.585 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-03-04T20:36:04.586Z,1741120564.586 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-03-04T20:36:04.587Z,1741120564.587 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 9038
2025-03-04T20:36:04.591Z,1741120564.591 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-03-04T20:36:04.592Z,1741120564.592 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-03-04T20:36:04.592Z,1741120564.592 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9039
2025-03-04T20:36:04.594Z,1741120564.594 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-03-04T20:36:04.595Z,1741120564.595 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-03-04T20:36:04.595Z,1741120564.595 [logger ThreadHandler](INFO): Protected caller Thread ID is 9040
2025-03-04T20:36:04.599Z,1741120564.599 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-03-04T20:36:04.600Z,1741120564.600 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-03-04T20:36:04.601Z,1741120564.601 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-03-04T20:36:04.833Z,1741120564.833 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-03-04T20:36:04.834Z,1741120564.834 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-03-04T20:36:05.048Z,1741120565.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-03-04T20:36:05.048Z,1741120565.048 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-03-04T20:36:05.154Z,1741120565.154 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-03-04T20:36:05.154Z,1741120565.154 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-03-04T20:36:05.341Z,1741120565.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-03-04T20:36:05.341Z,1741120565.341 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-03-04T20:36:05.839Z,1741120565.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-03-04T20:36:05.840Z,1741120565.840 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-03-04T20:36:05.978Z,1741120565.978 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-03-04T20:36:05.979Z,1741120565.979 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-03-04T20:36:06.251Z,1741120566.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-03-04T20:36:06.252Z,1741120566.252 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-03-04T20:36:06.466Z,1741120566.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-03-04T20:36:06.466Z,1741120566.466 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-03-04T20:36:07.026Z,1741120567.026 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-03-04T20:36:07.026Z,1741120567.026 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-03-04T20:36:07.437Z,1741120567.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-03-04T20:36:07.438Z,1741120567.438 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-03-04T20:36:07.527Z,1741120567.527 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-03-04T20:36:07.909Z,1741120567.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-03-04T20:36:07.910Z,1741120567.910 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-03-04T20:36:08.055Z,1741120568.055 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-03-04T20:36:08.055Z,1741120568.055 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-03-04T20:36:08.897Z,1741120568.897 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-03-04T20:36:08.898Z,1741120568.898 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-03-04T20:36:09.246Z,1741120569.246 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-03-04T20:36:09.247Z,1741120569.247 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-03-04T20:36:09.534Z,1741120569.534 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-aku/
2025-03-04T20:36:09.534Z,1741120569.534 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/secure.cfg
2025-03-04T20:36:09.630Z,1741120569.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/logger.cfg
2025-03-04T20:36:09.745Z,1741120569.745 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/vehicle.cfg
2025-03-04T20:36:09.858Z,1741120569.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/BIT.cfg
2025-03-04T20:36:09.957Z,1741120569.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Simulator.cfg
2025-03-04T20:36:10.052Z,1741120570.052 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Servo.cfg
2025-03-04T20:36:10.164Z,1741120570.164 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Science.cfg
2025-03-04T20:36:10.315Z,1741120570.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Sensor.cfg
2025-03-04T20:36:10.547Z,1741120570.547 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Control.cfg
2025-03-04T20:36:10.659Z,1741120570.659 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Battery.cfg
2025-03-04T20:36:10.941Z,1741120570.941 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-03-04T20:36:10.942Z,1741120570.942 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-03-04T20:36:10.962Z,1741120570.962 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-03-04T20:36:11.333Z,1741120571.333 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-03-04T20:36:11.334Z,1741120571.334 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-03-04T20:36:11.832Z,1741120571.832 [AHRS_M2] Loaded
2025-03-04T20:36:11.832Z,1741120571.832 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-03-04T20:36:11.870Z,1741120571.870 [BackseatComponent] Loaded
2025-03-04T20:36:11.870Z,1741120571.870 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-03-04T20:36:11.871Z,1741120571.871 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408AB4E0
2025-03-04T20:36:11.872Z,1741120571.872 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9119
2025-03-04T20:36:11.875Z,1741120571.875 [LcmUniversalReporter] Loaded
2025-03-04T20:36:11.875Z,1741120571.875 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-03-04T20:36:12.770Z,1741120572.770 [BPC1] Loaded
2025-03-04T20:36:12.770Z,1741120572.770 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-03-04T20:36:12.981Z,1741120572.981 [DAT] Loaded
2025-03-04T20:36:12.981Z,1741120572.981 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-03-04T20:36:12.982Z,1741120572.982 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408DB4E0
2025-03-04T20:36:12.983Z,1741120572.983 [DAT ThreadHandler](INFO): Protected caller Thread ID is 9120
2025-03-04T20:36:13.056Z,1741120573.056 [DataOverHttps] Loaded
2025-03-04T20:36:13.056Z,1741120573.056 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-03-04T20:36:13.057Z,1741120573.057 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090B4E0
2025-03-04T20:36:13.057Z,1741120573.057 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9121
2025-03-04T20:36:13.080Z,1741120573.080 [Depth_Keller] Loaded
2025-03-04T20:36:13.080Z,1741120573.080 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-03-04T20:36:13.085Z,1741120573.085 [DropWeight] Loaded
2025-03-04T20:36:13.085Z,1741120573.085 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-03-04T20:36:13.149Z,1741120573.149 [NAL9602] Loaded
2025-03-04T20:36:13.150Z,1741120573.150 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-03-04T20:36:13.179Z,1741120573.179 [Onboard] Loaded
2025-03-04T20:36:13.179Z,1741120573.179 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-03-04T20:36:13.180Z,1741120573.180 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093B4E0
2025-03-04T20:36:13.181Z,1741120573.181 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9122
2025-03-04T20:36:13.194Z,1741120573.194 [Power24vConverter] Loaded
2025-03-04T20:36:13.194Z,1741120573.194 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-03-04T20:36:13.211Z,1741120573.211 [Radio_Surface] Loaded
2025-03-04T20:36:13.211Z,1741120573.211 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-03-04T20:36:13.212Z,1741120573.212 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096B4E0
2025-03-04T20:36:13.213Z,1741120573.213 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9123
2025-03-04T20:36:13.228Z,1741120573.228 [Sonardyne_Nano] Loaded
2025-03-04T20:36:13.228Z,1741120573.228 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-03-04T20:36:13.229Z,1741120573.229 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-03-04T20:36:13.229Z,1741120573.229 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-03-04T20:36:13.364Z,1741120573.364 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-03-04T20:36:13.364Z,1741120573.364 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-03-04T20:36:13.418Z,1741120573.418 [VerticalControl](DEBUG): Construct VerticalControl.
2025-03-04T20:36:13.478Z,1741120573.478 [VerticalControl] Loaded
2025-03-04T20:36:13.478Z,1741120573.478 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-03-04T20:36:13.481Z,1741120573.481 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-03-04T20:36:13.529Z,1741120573.529 [HorizontalControl] Loaded
2025-03-04T20:36:13.529Z,1741120573.529 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-03-04T20:36:13.531Z,1741120573.531 [SpeedControl](DEBUG): Construct SpeedControl.
2025-03-04T20:36:13.535Z,1741120573.535 [SpeedControl] Loaded
2025-03-04T20:36:13.535Z,1741120573.535 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-03-04T20:36:13.538Z,1741120573.538 [LoopControl](DEBUG): Construct LoopControl.
2025-03-04T20:36:13.538Z,1741120573.538 [LoopControl] Loaded
2025-03-04T20:36:13.538Z,1741120573.538 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-03-04T20:36:13.539Z,1741120573.539 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-03-04T20:36:13.539Z,1741120573.539 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-03-04T20:36:13.550Z,1741120573.550 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-03-04T20:36:13.550Z,1741120573.550 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-03-04T20:36:13.579Z,1741120573.579 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-03-04T20:36:13.580Z,1741120573.580 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-03-04T20:36:13.693Z,1741120573.693 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-03-04T20:36:13.693Z,1741120573.693 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-03-04T20:36:13.707Z,1741120573.707 [NavChart] Loaded
2025-03-04T20:36:13.708Z,1741120573.708 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-03-04T20:36:13.713Z,1741120573.713 [UniversalFixResidualReporter] Loaded
2025-03-04T20:36:13.713Z,1741120573.713 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-03-04T20:36:13.714Z,1741120573.714 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-03-04T20:36:13.714Z,1741120573.714 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-03-04T20:36:13.935Z,1741120573.935 [SBIT](DEBUG): Construct Startup Built In Test.
2025-03-04T20:36:13.944Z,1741120573.944 [SBIT] Loaded
2025-03-04T20:36:13.944Z,1741120573.944 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-03-04T20:36:13.947Z,1741120573.947 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-03-04T20:36:13.960Z,1741120573.960 [IBIT] Loaded
2025-03-04T20:36:13.960Z,1741120573.960 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-03-04T20:36:13.966Z,1741120573.966 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-03-04T20:36:14.072Z,1741120574.072 [CBIT] Loaded
2025-03-04T20:36:14.072Z,1741120574.072 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-03-04T20:36:14.073Z,1741120574.073 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-03-04T20:36:14.073Z,1741120574.073 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-03-04T20:36:14.248Z,1741120574.248 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-03-04T20:36:14.249Z,1741120574.249 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-03-04T20:36:14.384Z,1741120574.384 [BuoyancyServo] Loaded
2025-03-04T20:36:14.384Z,1741120574.384 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-03-04T20:36:14.406Z,1741120574.406 [MassServo] Loaded
2025-03-04T20:36:14.406Z,1741120574.406 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-03-04T20:36:14.426Z,1741120574.426 [RudderServo] Loaded
2025-03-04T20:36:14.427Z,1741120574.427 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-03-04T20:36:14.444Z,1741120574.444 [ThrusterHE] Loaded
2025-03-04T20:36:14.444Z,1741120574.444 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-03-04T20:36:14.445Z,1741120574.445 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-03-04T20:36:14.445Z,1741120574.445 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-03-04T20:36:14.762Z,1741120574.762 [CTD_Seabird] Loaded
2025-03-04T20:36:14.762Z,1741120574.762 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-03-04T20:36:14.763Z,1741120574.763 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BA14E0
2025-03-04T20:36:14.763Z,1741120574.763 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9124
2025-03-04T20:36:14.799Z,1741120574.799 [ESPComponent] Loaded
2025-03-04T20:36:14.799Z,1741120574.799 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-03-04T20:36:14.821Z,1741120574.821 [PAR_Licor] Loaded
2025-03-04T20:36:14.821Z,1741120574.821 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-03-04T20:36:14.867Z,1741120574.867 [WetLabsBB2FL] Loaded
2025-03-04T20:36:14.867Z,1741120574.867 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-03-04T20:36:14.868Z,1741120574.868 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BD14E0
2025-03-04T20:36:14.869Z,1741120574.869 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9125
2025-03-04T20:36:14.869Z,1741120574.869 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-03-04T20:36:14.870Z,1741120574.870 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-03-04T20:36:14.921Z,1741120574.921 [DepthRateCalculator] Loaded
2025-03-04T20:36:14.921Z,1741120574.921 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-03-04T20:36:14.926Z,1741120574.926 [PitchRateCalculator] Loaded
2025-03-04T20:36:14.926Z,1741120574.926 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-03-04T20:36:14.936Z,1741120574.936 [SpeedCalculator] Loaded
2025-03-04T20:36:14.936Z,1741120574.936 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-03-04T20:36:14.940Z,1741120574.940 [YawRateCalculator] Loaded
2025-03-04T20:36:14.941Z,1741120574.941 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-03-04T20:36:14.960Z,1741120574.960 [ElevatorOffsetCalculator] Loaded
2025-03-04T20:36:14.960Z,1741120574.960 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-03-04T20:36:14.961Z,1741120574.961 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-03-04T20:36:14.961Z,1741120574.961 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-03-04T20:36:15.019Z,1741120575.019 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-03-04T20:36:15.026Z,1741120575.026 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-03-04T20:36:15.029Z,1741120575.029 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-03-04T20:36:15.040Z,1741120575.040 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-03-04T20:36:15.041Z,1741120575.041 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C5E4E0
2025-03-04T20:36:15.041Z,1741120575.041 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9126
2025-03-04T20:36:15.046Z,1741120575.046 [Supervisor](INFO): Main Thread ID is 8897
2025-03-04T20:36:15.046Z,1741120575.046 [Supervisor](DEBUG): Running supervisor.
2025-03-04T20:36:15.047Z,1741120575.047 [CommandExec ThreadHandler](INFO): Handler Thread ID is 9127
2025-03-04T20:36:15.047Z,1741120575.047 [CommandExec](INFO): Initializing the command executive.
2025-03-04T20:36:15.049Z,1741120575.049 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9128
2025-03-04T20:36:15.051Z,1741120575.051 [controlThread ThreadHandler](INFO): Handler Thread ID is 9129
2025-03-04T20:36:15.051Z,1741120575.051 [controlThread](DEBUG): Initializing ControlThread
2025-03-04T20:36:15.059Z,1741120575.059 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-03-04T20:36:15.060Z,1741120575.060 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-03-04T20:36:15.061Z,1741120575.061 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-03-04T20:36:15.062Z,1741120575.062 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-03-04T20:36:15.062Z,1741120575.062 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-03-04T20:36:15.063Z,1741120575.063 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-03-04T20:36:15.063Z,1741120575.063 [SBIT](INFO): Initialize SBIT Component.
2025-03-04T20:36:15.063Z,1741120575.063 [SBIT](IMPORTANT): git: 2025-02-24
2025-03-04T20:36:15.064Z,1741120575.064 [SBIT](INFO): git hash: a6046a38350dbb557659cdb2136a92a0beb43de0
2025-03-04T20:36:15.064Z,1741120575.064 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-03-04T20:36:15.065Z,1741120575.065 [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 Dec 4 01:17:04 UTC 2024
2025-03-04T20:36:15.067Z,1741120575.067 [SBIT](INFO): Beginning SBIT in 66.000000 seconds.
2025-03-04T20:36:15.067Z,1741120575.067 [IBIT](INFO): Initialize IBIT Component.
2025-03-04T20:36:15.068Z,1741120575.068 [CBIT](DEBUG): Initialize CBIT Component.
2025-03-04T20:36:15.069Z,1741120575.069 [logger ThreadHandler](INFO): Handler Thread ID is 9130
2025-03-04T20:36:15.081Z,1741120575.081 [CBIT](DEBUG): Initialized mux pins.
2025-03-04T20:36:15.081Z,1741120575.081 [CBIT](DEBUG): Initializing the watchdog timer.
2025-03-04T20:36:15.089Z,1741120575.089 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9131
2025-03-04T20:36:15.102Z,1741120575.102 [DAT ThreadHandler](INFO): Handler Thread ID is 9132
2025-03-04T20:36:15.102Z,1741120575.102 [DAT](INFO): Powering up
2025-03-04T20:36:15.103Z,1741120575.103 [DAT](DEBUG): Initializing DAT.
2025-03-04T20:36:15.105Z,1741120575.105 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-03-04T20:36:15.105Z,1741120575.105 [CBIT](DEBUG): Initializing heartbeat.
2025-03-04T20:36:15.107Z,1741120575.107 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9134
2025-03-04T20:36:15.109Z,1741120575.109 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-03-04T20:36:15.118Z,1741120575.118 [Onboard ThreadHandler](INFO): Handler Thread ID is 9135
2025-03-04T20:36:15.134Z,1741120575.134 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9136
2025-03-04T20:36:15.150Z,1741120575.150 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9137
2025-03-04T20:36:15.150Z,1741120575.150 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-03-04T20:36:15.154Z,1741120575.154 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9139
2025-03-04T20:36:15.157Z,1741120575.157 [WetLabsBB2FL](INFO): Powering up
2025-03-04T20:36:15.159Z,1741120575.159 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9141
2025-03-04T20:36:15.161Z,1741120575.161 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-03-04T20:36:15.161Z,1741120575.161 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-03-04T20:36:15.161Z,1741120575.161 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-03-04T20:36:15.162Z,1741120575.162 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-03-04T20:36:15.162Z,1741120575.162 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-03-04T20:36:15.162Z,1741120575.162 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-03-04T20:36:15.162Z,1741120575.162 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-03-04T20:36:15.162Z,1741120575.162 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-03-04T20:36:15.177Z,1741120575.177 [CBIT](DEBUG): Deactivating GF circuits.
2025-03-04T20:36:15.177Z,1741120575.177 [CBIT](DEBUG): Deactivating emergency mode.
2025-03-04T20:36:15.217Z,1741120575.217 [CBIT](DEBUG): Backplane powered.
2025-03-04T20:36:15.221Z,1741120575.221 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-03-04T20:36:15.222Z,1741120575.222 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-03-04T20:36:15.222Z,1741120575.222 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-03-04T20:36:15.222Z,1741120575.222 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-03-04T20:36:15.223Z,1741120575.223 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-03-04T20:36:15.224Z,1741120575.224 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-03-04T20:36:15.225Z,1741120575.225 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-03-04T20:36:15.225Z,1741120575.225 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-03-04T20:36:15.226Z,1741120575.226 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-03-04T20:36:15.306Z,1741120575.306 [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-03-04T20:36:15.310Z,1741120575.310 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-04T20:36:15.352Z,1741120575.352 [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-03-04T20:36:15.352Z,1741120575.352 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-03-04T20:36:15.352Z,1741120575.352 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-03-04T20:36:15.366Z,1741120575.366 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-03-04T20:36:15.541Z,1741120575.541 [Radio_Surface](INFO): Powering up
2025-03-04T20:36:15.625Z,1741120575.625 [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-03-04T20:36:15.650Z,1741120575.650 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-03-04T20:36:15.652Z,1741120575.652 [Default:A.Wait](DEBUG): Construct Wait.
2025-03-04T20:36:15.654Z,1741120575.654 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-04T20:36:15.687Z,1741120575.687 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-04T20:36:15.714Z,1741120575.714 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-04T20:36:15.721Z,1741120575.721 [Default:E.Execute](DEBUG): Construct Execute.
2025-03-04T20:36:15.724Z,1741120575.724 [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-03-04T20:36:15.753Z,1741120575.753 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-04T20:36:15.773Z,1741120575.773 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-03-04T20:36:15.843Z,1741120575.843 [Power24vConverter](INFO): Powering up.
2025-03-04T20:36:15.844Z,1741120575.844 [Sonardyne_Nano](INFO): Initializing.
2025-03-04T20:36:15.902Z,1741120575.902 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-03-04T20:36:15.909Z,1741120575.909 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-03-04T20:36:15.910Z,1741120575.910 [MassServo](DEBUG): Initializing EZServoServo.
2025-03-04T20:36:15.917Z,1741120575.917 [MassServo](DEBUG): Initializing MassServo.
2025-03-04T20:36:15.918Z,1741120575.918 [RudderServo](DEBUG): Initializing EZServoServo.
2025-03-04T20:36:15.925Z,1741120575.925 [RudderServo](DEBUG): Initializing RudderServo.
2025-03-04T20:36:15.926Z,1741120575.926 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-03-04T20:36:15.933Z,1741120575.933 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-03-04T20:36:16.206Z,1741120576.206 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2025-03-04T20:36:16.206Z,1741120576.206 [DropWeight] Hardware Fault, FailCount= 1
2025-03-04T20:36:16.206Z,1741120576.206 [DropWeight](ERROR): Hardware Fault
2025-03-04T20:36:16.231Z,1741120576.231 [CommandExec](FAULT): Scheduling is paused
2025-03-04T20:36:16.232Z,1741120576.232 [CBIT](INFO): Critical error at 20250304T203616
2025-03-04T20:36:16.232Z,1741120576.232 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-03-04T20:36:16.242Z,1741120576.242 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-03-04T20:36:16.243Z,1741120576.243 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-03-04T20:36:16.598Z,1741120576.598 [CBIT](INFO): Critical error at 20250304T203616
2025-03-04T20:36:17.265Z,1741120577.265 [WetLabsBB2FL](INFO): Powering down
2025-03-04T20:36:17.783Z,1741120577.783 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-03-04T20:36:19.069Z,1741120579.069 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2409
2025-03-04T20:36:19.425Z,1741120579.425 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging
2025-03-04T20:36:21.662Z,1741120581.662 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-03-04T20:36:22.182Z,1741120582.182 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-03-04T20:36:26.698Z,1741120586.698 [DAT](INFO): DAT read: 

2025-03-04T20:36:26.699Z,1741120586.699 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2025-03-04T20:36:28.210Z,1741120588.210 [DAT](INFO): DAT read: MF Frequency Band

2025-03-04T20:36:28.211Z,1741120588.211 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2025-03-04T20:36:28.212Z,1741120588.212 [DAT](INFO): DAT read: Mar  4 2025 20:36:23 

2025-03-04T20:36:29.470Z,1741120589.470 [DAT](INFO): DAT read: Features enabled [Bearing]

2025-03-04T20:36:29.471Z,1741120589.471 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2025-03-04T20:36:29.472Z,1741120589.472 [DAT](INFO): commRate: 800
2025-03-04T20:36:31.537Z,1741120591.537 [DAT](INFO): entering command mode
2025-03-04T20:36:31.738Z,1741120591.738 [DAT](INFO): DAT read: 

2025-03-04T20:36:31.738Z,1741120591.738 [DAT](INFO): DAT read: user:1>

2025-03-04T20:36:31.738Z,1741120591.738 [DAT](INFO): setting verbose to 3
2025-03-04T20:36:31.990Z,1741120591.990 [DAT](INFO): DAT read: user:1>

2025-03-04T20:36:31.991Z,1741120591.991 [DAT](INFO): DAT read: Verbose         | 3           

2025-03-04T20:36:31.991Z,1741120591.991 [DAT](INFO): set verbose to 3
2025-03-04T20:36:31.992Z,1741120591.992 [DAT](INFO): setting DatVerbose to 27440
2025-03-04T20:36:32.242Z,1741120592.242 [DAT](INFO): DAT read: user:2>

2025-03-04T20:36:32.243Z,1741120592.243 [DAT](INFO): DAT read: DatVerbose      | 27440       

2025-03-04T20:36:32.243Z,1741120592.243 [DAT](INFO): set DatVerbose to 27440
2025-03-04T20:36:32.243Z,1741120592.243 [DAT](INFO): setting transmit power to 8
2025-03-04T20:36:32.494Z,1741120592.494 [DAT](INFO): DAT read: user:3>

2025-03-04T20:36:32.495Z,1741120592.495 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2025-03-04T20:36:32.495Z,1741120592.495 [DAT](INFO): set transmit power to 8
2025-03-04T20:36:32.495Z,1741120592.495 [DAT](INFO): setting local address to 2
2025-03-04T20:36:32.746Z,1741120592.746 [DAT](INFO): DAT read: user:4>

2025-03-04T20:36:32.747Z,1741120592.747 [DAT](INFO): DAT read: LocalAddr       | 2           

2025-03-04T20:36:32.747Z,1741120592.747 [DAT](INFO): set local address to 2
2025-03-04T20:36:32.748Z,1741120592.748 [DAT](INFO): Setting time to: 20:36:32 And date to:3/4/2025
2025-03-04T20:36:32.998Z,1741120592.998 [DAT](INFO): DAT read: user:5>

2025-03-04T20:36:32.999Z,1741120592.999 [DAT](INFO): DAT read: Tue Mar 4, 2025  20:36:32  

2025-03-04T20:36:32.999Z,1741120592.999 [DAT](INFO): Local DAT time set to Tue Mar 4, 2025  20:36:32  

2025-03-04T20:36:43.238Z,1741120603.238 [NAL9602](INFO): Powering up NAL9602
2025-03-04T20:36:54.150Z,1741120614.150 [NAL9602](INFO): NAL9602 initialized
2025-03-04T20:37:21.771Z,1741120641.771 [SBIT](IMPORTANT): Beginning Startup BIT
2025-03-04T20:37:21.788Z,1741120641.788 [CBIT](IMPORTANT): Beginning ground fault scan
2025-03-04T20:37:33.098Z,1741120653.098 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.030726
CHAN A1 (24V): -0.000334
CHAN A2 (12V): -0.000435
CHAN A3 (5V): -0.002049
CHAN B0 (3.3V): -0.000910
CHAN B1 (3.15aV): -0.001847
CHAN B2 (3.15bV): -0.001464
CHAN B3 (GND): -0.001986
OPEN: 0.005303
Full Scale: +/- 1 mA
2025-03-04T20:37:35.135Z,1741120655.135 [SBIT](ERROR): Could not read elevatorAngleReader_.
2025-03-04T20:38:01.759Z,1741120681.759 [SBIT](ERROR): Could not read elevatorAngleReader_.
2025-03-04T20:38:01.759Z,1741120681.759 [SBIT](FAULT): Control surface position failure.
2025-03-04T20:38:15.503Z,1741120695.503 [SBIT](ERROR): Could not read elevatorAngleReader_.
2025-03-04T20:38:15.503Z,1741120695.503 [SBIT](FAULT): Control surface position failure.
2025-03-04T20:38:15.935Z,1741120695.935 [SBIT](CRITICAL): SBIT FAILED
2025-03-04T20:38:15.935Z,1741120695.935 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-03-04T20:38:15.936Z,1741120695.936 [SBIT](IMPORTANT): BioacousticsDataBridge.loadAtStartup=0 bool;

2025-03-04T20:38:15.936Z,1741120695.936 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool;

2025-03-04T20:38:15.936Z,1741120695.936 [SBIT](IMPORTANT): Courier mostRecent latitude_fix;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): Courier mostRecent longitude_fix;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): Courier mostRecent time_fix;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): DATMMP.loadAtStartup=0 bool;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=5 minute;

2025-03-04T20:38:15.937Z,1741120695.937 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): ElevatorServo.loadAtStartup=0 bool;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): Express none PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=0.1 ampere_hour;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): SpeedControl.rollOptimum=0.950000 m/s;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=305.318315 cubic_centimeter;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.5 degree;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): VerticalControl.kdPitchMass=0.1 second;

2025-03-04T20:38:15.938Z,1741120695.938 [SBIT](IMPORTANT): VerticalControl.kiPitchMass=0.001 reciprocal_second;

2025-03-04T20:38:15.939Z,1741120695.939 [SBIT](IMPORTANT): VerticalControl.kpDepthBuoy=30 ratio;

2025-03-04T20:38:15.939Z,1741120695.939 [SBIT](IMPORTANT): VerticalControl.kpPitchMass=0.1 none;

2025-03-04T20:38:15.939Z,1741120695.939 [SBIT](IMPORTANT): VerticalControl.massDeadband=0 millimeter;

2025-03-04T20:38:15.939Z,1741120695.939 [SBIT](IMPORTANT): VerticalControl.massDefault=11.647778 millimeter;

2025-03-04T20:38:15.939Z,1741120695.939 [SBIT](IMPORTANT): VerticalControl.massOnlyForceInt=1 bool;

2025-03-04T20:38:15.941Z,1741120695.941 [CBIT](INFO): Critical error at 20250304T203815
2025-03-04T20:38:16.187Z,1741120696.187 [MissionManager](IMPORTANT): Started mission Startup
2025-03-04T20:38:16.187Z,1741120696.187 [Startup] Running Loop=1
2025-03-04T20:38:16.188Z,1741120696.188 [Startup](DEBUG): Aggregate::initialize Startup
2025-03-04T20:38:16.188Z,1741120696.188 [Startup:A.GoToSurface] Running Loop=1
2025-03-04T20:38:16.188Z,1741120696.188 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-04T20:38:16.188Z,1741120696.188 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-04T20:38:16.190Z,1741120696.190 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-04T20:38:16.190Z,1741120696.190 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-04T20:38:16.190Z,1741120696.190 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-04T20:38:16.191Z,1741120696.191 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-04T20:38:16.191Z,1741120696.191 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-04T20:38:16.193Z,1741120696.193 [Startup:StartupSatComms] Running Loop=1
2025-03-04T20:38:16.193Z,1741120696.193 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-03-04T20:38:16.193Z,1741120696.193 [Startup:StartupSatComms:A] Running Loop=1
2025-03-04T20:38:16.652Z,1741120696.652 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-03-04T20:38:27.332Z,1741120707.332 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004991
2025-03-04T20:39:15.170Z,1741120755.170 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-03-04T20:39:15.170Z,1741120755.170 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T20:39:15.461Z,1741120755.461 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T20:39:15.861Z,1741120755.861 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T20:39:15.861Z,1741120755.861 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-03-04T20:39:16.443Z,1741120756.443 [Startup:StartupSatComms:A](INFO): Timed out from 2025-03-04T20:38:16.2Z
2025-03-04T20:39:16.443Z,1741120756.443 [Startup:StartupSatComms:A] Stopped
2025-03-04T20:39:16.443Z,1741120756.443 [Startup:StartupSatComms:B] Running Loop=1
2025-03-04T20:39:16.815Z,1741120756.815 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-04T20:39:25.292Z,1741120765.292 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250226T182812/Courier0174.lzma
2025-03-04T20:39:26.288Z,1741120766.288 [DataOverHttps](INFO): Moved sent file to Logs/20250226T182812/Courier0174.lzma.bak
2025-03-04T20:39:26.288Z,1741120766.288 [DataOverHttps](INFO): SBD MOMSN=23990325
2025-03-04T20:39:42.834Z,1741120782.834 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20250304T203346/Courier0000.lzma
2025-03-04T20:39:43.835Z,1741120783.835 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203346/Courier0000.lzma.bak
2025-03-04T20:39:43.835Z,1741120783.835 [DataOverHttps](INFO): SBD MOMSN=23990327
2025-03-04T20:40:01.017Z,1741120801.017 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20250304T203604/Courier0000.lzma
2025-03-04T20:40:02.019Z,1741120802.019 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203604/Courier0000.lzma.bak
2025-03-04T20:40:02.019Z,1741120802.019 [DataOverHttps](INFO): SBD MOMSN=23990335
2025-03-04T20:40:16.556Z,1741120816.556 [Startup:StartupSatComms:B](INFO): Timed out from 2025-03-04T20:39:16.4Z
2025-03-04T20:40:16.556Z,1741120816.556 [Startup:StartupSatComms:B] Stopped
2025-03-04T20:40:16.556Z,1741120816.556 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-03-04T20:40:16.557Z,1741120816.557 [Startup:StartupSatComms] Stopped
2025-03-04T20:40:16.557Z,1741120816.557 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-03-04T20:40:16.558Z,1741120816.558 [Startup](INFO): Completed Startup
2025-03-04T20:40:16.558Z,1741120816.558 [MissionManager](INFO): Startup is completed.
2025-03-04T20:40:16.558Z,1741120816.558 [MissionManager](INFO): Uninitializing Mission Startup
2025-03-04T20:40:16.558Z,1741120816.558 [Startup] Stopped
2025-03-04T20:40:16.559Z,1741120816.559 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-03-04T20:40:16.559Z,1741120816.559 [Startup:A.GoToSurface] Stopped
2025-03-04T20:40:16.559Z,1741120816.559 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-04T20:40:16.952Z,1741120816.952 [MissionManager](IMPORTANT): Started mission Default
2025-03-04T20:40:16.952Z,1741120816.952 [Default] Running Loop=1
2025-03-04T20:40:16.952Z,1741120816.952 [Default](DEBUG): Aggregate::initialize Default
2025-03-04T20:40:16.952Z,1741120816.952 [Default:B.GoToSurface] Running Loop=1
2025-03-04T20:40:16.953Z,1741120816.953 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-04T20:40:16.953Z,1741120816.953 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-04T20:40:16.953Z,1741120816.953 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-04T20:40:16.954Z,1741120816.954 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-04T20:40:16.954Z,1741120816.954 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-04T20:40:16.954Z,1741120816.954 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-04T20:40:16.955Z,1741120816.955 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-04T20:40:16.955Z,1741120816.955 [Default:A.Wait] Running Loop=1
2025-03-04T20:40:16.955Z,1741120816.955 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-04T20:40:17.527Z,1741120817.527 [DataOverHttps](INFO): Sending 556 bytes from file Logs/20250226T182812/Express0172.lzma
2025-03-04T20:40:18.523Z,1741120818.523 [DataOverHttps](INFO): Moved sent file to Logs/20250226T182812/Express0172.lzma.bak
2025-03-04T20:40:18.523Z,1741120818.523 [DataOverHttps](INFO): SBD MOMSN=23990347
2025-03-04T20:40:30.360Z,1741120830.360 [Default:A.Wait](INFO): Done Waiting.
2025-03-04T20:40:30.360Z,1741120830.360 [Default:A.Wait] Stopped
2025-03-04T20:40:30.360Z,1741120830.360 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T20:40:30.736Z,1741120830.736 [Default:CheckIn] Running Loop=1
2025-03-04T20:40:30.736Z,1741120830.736 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-04T20:40:30.736Z,1741120830.736 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-04T20:40:31.135Z,1741120831.135 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-04T20:41:41.238Z,1741120901.238 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:41:54.166Z,1741120914.166 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:41:57.450Z,1741120917.450 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-04T20:42:07.143Z,1741120927.143 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:42:16.070Z,1741120936.070 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-03-04T20:42:16.070Z,1741120936.070 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T20:42:16.353Z,1741120936.353 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T20:42:16.761Z,1741120936.761 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T20:42:16.761Z,1741120936.761 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-03-04T20:42:20.071Z,1741120940.071 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:42:33.426Z,1741120953.426 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:42:46.012Z,1741120966.012 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:42:58.566Z,1741120978.566 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:43:11.495Z,1741120991.495 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:43:24.018Z,1741121004.018 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:43:36.186Z,1741121016.186 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:43:48.711Z,1741121028.711 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2025-03-04T20:43:50.414Z,1741121030.414 [CommandExec](IMPORTANT): got command strobe off
2025-03-04T20:43:50.415Z,1741121030.415 [CommandExec](IMPORTANT): Deactivating strobe
2025-03-04T20:44:10.970Z,1741121050.970 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-03-04T20:44:10.978Z,1741121050.978 [BPC1](ERROR): Battery stick #62 (s/n: 00CC) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-03-04T20:44:10.978Z,1741121050.978 [BPC1](INFO): Calculating totals. Valid battery stick count: 51. Valid reserve battery stick count: 6.
2025-03-04T20:44:10.982Z,1741121050.982 [BPC1](INFO): Received data from all battery sticks.
2025-03-04T20:45:16.854Z,1741121116.854 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-03-04T20:45:16.854Z,1741121116.854 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T20:45:17.145Z,1741121117.145 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T20:45:17.549Z,1741121117.549 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T20:45:17.549Z,1741121117.549 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-03-04T20:45:31.042Z,1741121131.042 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-04T20:40:30.7Z
2025-03-04T20:45:31.042Z,1741121131.042 [Default:CheckIn:Read_GPS] Stopped
2025-03-04T20:45:31.042Z,1741121131.042 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-04T20:45:31.427Z,1741121131.427 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-04T20:45:32.413Z,1741121132.413 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250304T203604/Courier0004.lzma
2025-03-04T20:45:32.987Z,1741121132.987 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203604/Courier0004.lzma.bak
2025-03-04T20:45:32.987Z,1741121132.987 [DataOverHttps](INFO): SBD MOMSN=23990367
2025-03-04T20:45:49.744Z,1741121149.744 [DataOverHttps](INFO): Sending 87 bytes from file Logs/20250226T182812/Express0175.lzma
2025-03-04T20:45:56.674Z,1741121156.674 [DataOverHttps](INFO): Moved sent file to Logs/20250226T182812/Express0175.lzma.bak
2025-03-04T20:45:56.674Z,1741121156.674 [DataOverHttps](INFO): SBD MOMSN=23990369
2025-03-04T20:46:13.167Z,1741121173.167 [DataOverHttps](INFO): Sending 854 bytes from file Logs/20250304T203346/Express0001.lzma
2025-03-04T20:46:14.167Z,1741121174.167 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203346/Express0001.lzma.bak
2025-03-04T20:46:14.167Z,1741121174.167 [DataOverHttps](INFO): SBD MOMSN=23990372
2025-03-04T20:46:32.230Z,1741121192.230 [DataOverHttps](INFO): Sending 1203 bytes from file Logs/20250304T203604/Express0001.lzma
2025-03-04T20:46:33.515Z,1741121193.515 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203604/Express0001.lzma.bak
2025-03-04T20:46:33.516Z,1741121193.516 [DataOverHttps](INFO): SBD MOMSN=23990392
2025-03-04T20:46:49.577Z,1741121209.577 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20250304T203604/Express0005.lzma
2025-03-04T20:46:50.579Z,1741121210.579 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203604/Express0005.lzma.bak
2025-03-04T20:46:50.579Z,1741121210.579 [DataOverHttps](INFO): SBD MOMSN=23990432
2025-03-04T20:46:52.683Z,1741121212.683 [Default:CheckIn:Read_Iridium] Stopped
2025-03-04T20:46:52.683Z,1741121212.683 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-04T20:46:52.683Z,1741121212.683 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T20:46:55.866Z,1741121215.866 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-04T20:46:55.866Z,1741121215.866 [NAL9602] Data Fault, FailCount= 1
2025-03-04T20:46:55.866Z,1741121215.866 [NAL9602](ERROR): Data Fault
2025-03-04T20:46:56.181Z,1741121216.181 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-04T20:46:56.274Z,1741121216.274 [NAL9602](INFO): Powering down
2025-03-04T20:46:57.397Z,1741121217.397 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-04T20:46:57.397Z,1741121217.397 [NAL9602] No Fault, FailCount= 1
2025-03-04T20:47:26.614Z,1741121246.614 [NAL9602](INFO): Powering up NAL9602
2025-03-04T20:47:37.526Z,1741121257.526 [NAL9602](INFO): NAL9602 initialized
2025-03-04T20:48:17.947Z,1741121297.947 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-03-04T20:48:17.947Z,1741121297.947 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T20:48:18.245Z,1741121298.245 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T20:48:18.637Z,1741121298.637 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T20:48:18.637Z,1741121298.637 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-03-04T20:51:16.569Z,1741121476.569 [CBIT](INFO): Clearing failed state for component DropWeight
2025-03-04T20:51:16.569Z,1741121476.569 [DropWeight] No Fault, FailCount= 1
2025-03-04T20:51:19.110Z,1741121479.110 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-03-04T20:51:19.110Z,1741121479.110 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T20:51:19.393Z,1741121479.393 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T20:51:19.789Z,1741121479.789 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T20:51:19.789Z,1741121479.789 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-03-04T20:51:53.099Z,1741121513.099 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-04T20:51:53.099Z,1741121513.099 [Default:CheckIn:C.Wait] Stopped
2025-03-04T20:51:53.099Z,1741121513.099 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T20:51:53.100Z,1741121513.100 [Default:CheckIn:D] Running Loop=1
2025-03-04T20:51:53.496Z,1741121513.496 [Default:CheckIn:D] Stopped
2025-03-04T20:51:53.496Z,1741121513.496 [Default:CheckIn:E] Running Loop=1
2025-03-04T20:51:53.931Z,1741121513.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  11.609062 min 
2025-03-04T20:51:53.931Z,1741121513.931 [Default:CheckIn:E] Stopped
2025-03-04T20:51:53.931Z,1741121513.931 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-04T20:51:53.932Z,1741121513.932 [Default:CheckIn] Stopped
2025-03-04T20:51:53.932Z,1741121513.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-04T20:51:53.932Z,1741121513.932 [Default:CheckIn](INFO): Running loop #2
2025-03-04T20:51:53.932Z,1741121513.932 [Default:CheckIn] Running Loop=2
2025-03-04T20:51:53.932Z,1741121513.932 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-04T20:51:53.932Z,1741121513.932 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-04T20:54:20.177Z,1741121660.177 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-03-04T20:54:20.177Z,1741121660.177 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T20:54:20.497Z,1741121660.497 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T20:54:20.889Z,1741121660.889 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T20:54:20.889Z,1741121660.889 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-03-04T20:56:54.110Z,1741121814.110 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-04T20:51:53.9Z
2025-03-04T20:56:54.110Z,1741121814.110 [Default:CheckIn:Read_GPS] Stopped
2025-03-04T20:56:54.110Z,1741121814.110 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-04T20:57:01.576Z,1741121821.576 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250304T203604/Courier0007.lzma
2025-03-04T20:57:02.579Z,1741121822.579 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203604/Courier0007.lzma.bak
2025-03-04T20:57:02.579Z,1741121822.579 [DataOverHttps](INFO): SBD MOMSN=23990469
2025-03-04T20:57:18.872Z,1741121838.872 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20250304T203604/Express0008.lzma
2025-03-04T20:57:19.871Z,1741121839.871 [DataOverHttps](INFO): Moved sent file to Logs/20250304T203604/Express0008.lzma.bak
2025-03-04T20:57:19.871Z,1741121839.871 [DataOverHttps](INFO): SBD MOMSN=23990471
2025-03-04T20:57:21.398Z,1741121841.398 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-03-04T20:57:21.399Z,1741121841.399 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T20:57:21.677Z,1741121841.677 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T20:57:21.782Z,1741121841.782 [Default:CheckIn:Read_Iridium] Stopped
2025-03-04T20:57:21.782Z,1741121841.782 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-04T20:57:21.782Z,1741121841.782 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T20:57:22.069Z,1741121842.069 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T20:57:22.069Z,1741121842.069 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-03-04T20:57:39.218Z,1741121859.218 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-04T20:57:39.219Z,1741121859.219 [NAL9602] Data Fault, FailCount= 2
2025-03-04T20:57:39.219Z,1741121859.219 [NAL9602](ERROR): Data Fault
2025-03-04T20:57:39.517Z,1741121859.517 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-04T20:57:39.622Z,1741121859.622 [NAL9602](INFO): Powering down
2025-03-04T20:57:40.733Z,1741121860.733 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-04T20:57:40.733Z,1741121860.733 [NAL9602] No Fault, FailCount= 2
2025-03-04T20:58:09.986Z,1741121889.986 [NAL9602](INFO): Powering up NAL9602
2025-03-04T20:58:20.895Z,1741121900.895 [NAL9602](INFO): NAL9602 initialized
2025-03-04T21:00:22.272Z,1741122022.272 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-03-04T21:00:22.272Z,1741122022.272 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T21:00:22.545Z,1741122022.545 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T21:00:22.946Z,1741122022.946 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T21:00:22.946Z,1741122022.946 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-03-04T21:00:35.907Z,1741122035.907 [CommandExec](IMPORTANT): got command failComponent
2025-03-04T21:00:35.908Z,1741122035.908 [CommandExec](IMPORTANT): Failed components:
2025-03-04T21:00:35.908Z,1741122035.908 [CommandExec](IMPORTANT): No failed Components.
2025-03-04T21:02:22.403Z,1741122142.403 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-04T21:02:22.403Z,1741122142.403 [Default:CheckIn:C.Wait] Stopped
2025-03-04T21:02:22.403Z,1741122142.403 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:02:22.403Z,1741122142.403 [Default:CheckIn:D] Running Loop=1
2025-03-04T21:02:22.817Z,1741122142.817 [Default:CheckIn:D] Stopped
2025-03-04T21:02:22.818Z,1741122142.818 [Default:CheckIn:E] Running Loop=1
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  22.097752 min 
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn:E] Stopped
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn] Stopped
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn](INFO): Running loop #3
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn] Running Loop=3
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-04T21:02:23.212Z,1741122143.212 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-04T21:03:23.067Z,1741122203.067 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-03-04T21:03:23.067Z,1741122203.067 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T21:03:23.378Z,1741122203.378 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T21:03:23.785Z,1741122203.785 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T21:03:23.785Z,1741122203.785 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-03-04T21:03:36.086Z,1741122216.086 [CommandExec](IMPORTANT): got command report mod SpeedControl.speedCmd
2025-03-04T21:03:36.314Z,1741122216.314 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:03:41.128Z,1741122221.128 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/speed_step_lab.tl
2025-03-04T21:03:41.128Z,1741122221.128 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/speed_step_lab.tl
2025-03-04T21:03:41.128Z,1741122221.128 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/speed_step_lab.tl
2025-03-04T21:03:41.136Z,1741122221.136 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/speed_step_lab.tl
2025-03-04T21:03:41.214Z,1741122221.214 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/speed_step_lab.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="speed_step_lab">
    <Timeout Duration="P35M" />
    <Aggregate Id="Speedy">
        <Sequence Repeat="288" />
        <Aggregate Id="On">
            <Sequence />
            <Guidance:SetSpeed>
                <Parallel />
                <Setting>
                    <Guidance:SetSpeed.speed />
                    <Units:meter_per_second />
                    <Value>0.2</Value>
                </Setting>
            </Guidance:SetSpeed>
            <Syslog Severity="Important">Thruster On.</Syslog>
            <Guidance:Wait>
                <Sequence />
                <Timeout Duration="P0.5M" />
            </Guidance:Wait>
        </Aggregate>
        <Aggregate Id="Off">
            <Sequence />
            <Guidance:SetSpeed>
                <Parallel />
                <Setting>
                    <Guidance:SetSpeed.speed />
                    <Units:meter_per_second />
                    <Value>0.0</Value>
                </Setting>
            </Guidance:SetSpeed>
            <Syslog Severity="Important">Thruster Off.</Syslog>
            <Guidance:Wait>
                <Sequence />
                <Timeout Duration="P0.5M" />
            </Guidance:Wait>
        </Aggregate>
    </Aggregate>
</Mission>

2025-03-04T21:03:41.218Z,1741122221.218 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Construct.
2025-03-04T21:03:41.246Z,1741122221.246 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Construct Wait.
2025-03-04T21:03:41.248Z,1741122221.248 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Construct.
2025-03-04T21:03:41.272Z,1741122221.272 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Construct Wait.
2025-03-04T21:03:41.282Z,1741122221.282 [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 speed_step_lab {

  timeout duration=P35M

  aggregate Speedy {
    run in sequence repeat=288

aggregate On {
 run in sequence
      behavior Guidance:SetSpeed {
        run in parallel
        set speed = 0.2 meter_per_second
      }
      syslog important "Thruster On."

      behavior Guidance:Wait {
        run in sequence
        timeout duration=P0.5M
      }
      }

aggregate Off {
 run in sequence
  
      behavior Guidance:SetSpeed {
        run in parallel

        set speed = 0.0 meter_per_second
      }
      syslog important "Thruster Off."
             
      behavior Guidance:Wait {
        run in sequence
        timeout duration=P0.5M
      }      
     }
  }
}

2025-03-04T21:03:41.284Z,1741122221.284 [CommandExec](IMPORTANT): Running ./Missions/Engineering/speed_step_lab.tl
2025-03-04T21:03:41.651Z,1741122221.651 [Default] Stopped
2025-03-04T21:03:41.651Z,1741122221.651 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-04T21:03:41.651Z,1741122221.651 [Default:B.GoToSurface] Stopped
2025-03-04T21:03:41.651Z,1741122221.651 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-04T21:03:41.651Z,1741122221.651 [Default:CheckIn] Stopped
2025-03-04T21:03:41.651Z,1741122221.651 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-04T21:03:41.651Z,1741122221.651 [Default:CheckIn:Read_GPS] Stopped
2025-03-04T21:03:41.652Z,1741122221.652 [MissionManager](IMPORTANT): Started mission speed_step_lab
2025-03-04T21:03:41.652Z,1741122221.652 [speed_step_lab] Running Loop=1
2025-03-04T21:03:41.652Z,1741122221.652 [speed_step_lab](DEBUG): Aggregate::initialize speed_step_lab
2025-03-04T21:03:41.652Z,1741122221.652 [speed_step_lab:Speedy] Running Loop=1
2025-03-04T21:03:41.652Z,1741122221.652 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:03:41.652Z,1741122221.652 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:03:41.652Z,1741122221.652 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:03:41.653Z,1741122221.653 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:03:41.653Z,1741122221.653 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:03:41.653Z,1741122221.653 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:03:41.653Z,1741122221.653 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:03:41.653Z,1741122221.653 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:03:41.653Z,1741122221.653 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:03:41.654Z,1741122221.654 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:03:41.654Z,1741122221.654 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:03:41.835Z,1741122221.835 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:03:58.159Z,1741122238.159 [CommandExec](IMPORTANT): got command show variable THrusterHE
2025-03-04T21:03:58.302Z,1741122238.302 [CommandExec](IMPORTANT): ThrusterHE.loadControl (none)
2025-03-04T21:03:58.303Z,1741122238.303 [CommandExec](IMPORTANT): ThrusterHE.uart (none)
2025-03-04T21:03:58.303Z,1741122238.303 [CommandExec](IMPORTANT): ThrusterHE.baud (bit_per_second)
2025-03-04T21:03:58.390Z,1741122238.390 [CommandExec](IMPORTANT): ThrusterHE.loadAtStartup (bool)
2025-03-04T21:03:58.391Z,1741122238.391 [CommandExec](IMPORTANT): ThrusterHE.simulateHardware (bool)
2025-03-04T21:03:58.391Z,1741122238.391 [CommandExec](IMPORTANT): ThrusterHE.deviation (count)
2025-03-04T21:03:58.391Z,1741122238.391 [CommandExec](IMPORTANT): ThrusterHE.allowableBadVelocity (count)
2025-03-04T21:03:58.392Z,1741122238.392 [CommandExec](IMPORTANT): ThrusterHE.ratedSpeed (count)
2025-03-04T21:03:58.392Z,1741122238.392 [CommandExec](IMPORTANT): ThrusterHE.powerOnTimeout (second)
2025-03-04T21:03:58.392Z,1741122238.392 [CommandExec](IMPORTANT): ThrusterHE.bestEffortMode (bool)
2025-03-04T21:03:58.590Z,1741122238.590 [CommandExec](IMPORTANT): ThrusterHE.enableBroadcast (bool)
2025-03-04T21:03:58.590Z,1741122238.590 [CommandExec](IMPORTANT): ThrusterHE.component_voltage (volt)
2025-03-04T21:03:58.591Z,1741122238.591 [CommandExec](IMPORTANT): ThrusterHE.component_avgVoltage (volt)
2025-03-04T21:03:58.591Z,1741122238.591 [CommandExec](IMPORTANT): ThrusterHE.component_current (milliampere)
2025-03-04T21:03:58.592Z,1741122238.592 [CommandExec](IMPORTANT): ThrusterHE.component_avgCurrent (milliampere)
2025-03-04T21:03:58.592Z,1741122238.592 [CommandExec](IMPORTANT): ThrusterHE.component_discreteIn (bool)
2025-03-04T21:03:58.592Z,1741122238.592 [CommandExec](IMPORTANT): ThrusterHE.platform_propeller_rotation_rate (radian_per_second)
2025-03-04T21:04:11.904Z,1741122251.904 [CommandExec](IMPORTANT): got command report mod ThrusterHE.platform_propeller_rotation_rate
2025-03-04T21:04:11.948Z,1741122251.948 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:03:41.7Z
2025-03-04T21:04:11.948Z,1741122251.948 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:04:11.948Z,1741122251.948 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:04:11.948Z,1741122251.948 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:04:11.949Z,1741122251.949 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:04:11.950Z,1741122251.950 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:04:12.171Z,1741122252.171 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:04:12.351Z,1741122252.351 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:04:12.351Z,1741122252.351 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:04:12.352Z,1741122252.352 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:04:12.352Z,1741122252.352 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:04:12.352Z,1741122252.352 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:04:12.566Z,1741122252.566 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:04:13.016Z,1741122253.016 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:04:42.658Z,1741122282.658 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:04:12.4Z
2025-03-04T21:04:42.659Z,1741122282.659 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:04:42.659Z,1741122282.659 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:04:42.659Z,1741122282.659 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:04:42.659Z,1741122282.659 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:04:42.659Z,1741122282.659 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:04:42.659Z,1741122282.659 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy] Stopped
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy](INFO): Running loop #2
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy] Running Loop=2
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:04:42.660Z,1741122282.660 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:04:42.661Z,1741122282.661 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:04:42.661Z,1741122282.661 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:04:42.661Z,1741122282.661 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:04:43.053Z,1741122283.053 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:04:43.053Z,1741122283.053 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:04:43.053Z,1741122283.053 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:04:43.053Z,1741122283.053 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:04:43.207Z,1741122283.207 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:04:47.742Z,1741122287.742 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.487831 rad/s
2025-03-04T21:04:57.434Z,1741122297.434 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:05:03.506Z,1741122303.506 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:05:03.919Z,1741122303.919 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:05:04.294Z,1741122304.294 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:05:05.106Z,1741122305.106 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:05:05.514Z,1741122305.514 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:05:05.922Z,1741122305.922 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:05:06.318Z,1741122306.318 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:05:07.146Z,1741122307.146 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:05:09.559Z,1741122309.559 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:05:12.778Z,1741122312.778 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:05:13.356Z,1741122313.356 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:04:43.1Z
2025-03-04T21:05:13.356Z,1741122313.356 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:05:13.356Z,1741122313.356 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:05:13.356Z,1741122313.356 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:05:13.356Z,1741122313.356 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:05:13.356Z,1741122313.356 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:05:13.356Z,1741122313.356 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:05:13.357Z,1741122313.357 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:05:13.381Z,1741122313.381 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:05:13.381Z,1741122313.381 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:05:13.381Z,1741122313.381 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:05:13.381Z,1741122313.381 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:05:13.381Z,1741122313.381 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:05:13.758Z,1741122313.758 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:05:13.758Z,1741122313.758 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:05:13.758Z,1741122313.758 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:05:13.758Z,1741122313.758 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:05:13.950Z,1741122313.950 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:05:14.434Z,1741122314.434 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:05:44.059Z,1741122344.059 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:05:13.8Z
2025-03-04T21:05:44.059Z,1741122344.059 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:05:44.059Z,1741122344.059 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:05:44.059Z,1741122344.059 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy] Stopped
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy](INFO): Running loop #3
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy] Running Loop=3
2025-03-04T21:05:44.060Z,1741122344.060 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:05:44.061Z,1741122344.061 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:05:44.061Z,1741122344.061 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:05:44.061Z,1741122344.061 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:05:44.061Z,1741122344.061 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:05:44.061Z,1741122344.061 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:05:44.483Z,1741122344.483 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:05:44.483Z,1741122344.483 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:05:44.483Z,1741122344.483 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:05:44.483Z,1741122344.483 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:05:44.660Z,1741122344.660 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:05:58.814Z,1741122358.814 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:05:59.150Z,1741122359.150 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-03-04T21:05:59.150Z,1741122359.150 [ThrusterHE](INFO): Powering down
2025-03-04T21:05:59.954Z,1741122359.954 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-03-04T21:06:00.074Z,1741122360.074 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-03-04T21:06:05.233Z,1741122365.233 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:06:05.630Z,1741122365.630 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-03-04T21:06:07.722Z,1741122367.722 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.904092 rad/s
2025-03-04T21:06:08.126Z,1741122368.126 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.071569 rad/s
2025-03-04T21:06:13.398Z,1741122373.398 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.660176 rad/s
2025-03-04T21:06:14.766Z,1741122374.766 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:05:44.5Z
2025-03-04T21:06:14.766Z,1741122374.766 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:06:14.766Z,1741122374.766 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:06:14.767Z,1741122374.767 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:06:14.768Z,1741122374.768 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:06:15.167Z,1741122375.167 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:06:15.167Z,1741122375.167 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:06:15.167Z,1741122375.167 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:06:15.167Z,1741122375.167 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:06:15.330Z,1741122375.330 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:06:15.859Z,1741122375.859 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:06:24.053Z,1741122384.053 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2025-03-04T21:06:24.053Z,1741122384.053 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T21:06:24.221Z,1741122384.221 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T21:06:24.634Z,1741122384.634 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T21:06:24.634Z,1741122384.634 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2025-03-04T21:06:45.468Z,1741122405.468 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:06:15.2Z
2025-03-04T21:06:45.468Z,1741122405.468 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:06:45.468Z,1741122405.468 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:06:45.468Z,1741122405.468 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:06:45.468Z,1741122405.468 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:06:45.468Z,1741122405.468 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:06:45.468Z,1741122405.468 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:06:45.469Z,1741122405.469 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:06:45.469Z,1741122405.469 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:06:45.469Z,1741122405.469 [speed_step_lab:Speedy] Stopped
2025-03-04T21:06:45.469Z,1741122405.469 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:06:45.469Z,1741122405.469 [speed_step_lab:Speedy](INFO): Running loop #4
2025-03-04T21:06:45.469Z,1741122405.469 [speed_step_lab:Speedy] Running Loop=4
2025-03-04T21:06:45.469Z,1741122405.469 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:06:45.470Z,1741122405.470 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:06:45.470Z,1741122405.470 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:06:45.470Z,1741122405.470 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:06:45.470Z,1741122405.470 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:06:45.470Z,1741122405.470 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:06:45.873Z,1741122405.873 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:06:45.873Z,1741122405.873 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:06:45.873Z,1741122405.873 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:06:45.873Z,1741122405.873 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:06:46.020Z,1741122406.020 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:06:50.558Z,1741122410.558 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.904092 rad/s
2025-03-04T21:06:50.959Z,1741122410.959 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 14.985397 rad/s
2025-03-04T21:06:51.354Z,1741122411.354 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 13.736614 rad/s
2025-03-04T21:06:51.758Z,1741122411.758 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.487831 rad/s
2025-03-04T21:06:56.610Z,1741122416.610 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 7.076437 rad/s
2025-03-04T21:07:06.710Z,1741122426.710 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:07:07.118Z,1741122427.118 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:07:07.554Z,1741122427.554 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:07:07.942Z,1741122427.942 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:07:08.335Z,1741122428.335 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:07:09.142Z,1741122429.142 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:07:09.539Z,1741122429.539 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:07:09.946Z,1741122429.946 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:07:14.810Z,1741122434.810 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:07:16.171Z,1741122436.171 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:06:45.9Z
2025-03-04T21:07:16.171Z,1741122436.171 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:07:16.172Z,1741122436.172 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:07:16.172Z,1741122436.172 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:07:16.172Z,1741122436.172 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:07:16.172Z,1741122436.172 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:07:16.172Z,1741122436.172 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:07:16.172Z,1741122436.172 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:07:16.173Z,1741122436.173 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:07:16.173Z,1741122436.173 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:07:16.173Z,1741122436.173 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:07:16.173Z,1741122436.173 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:07:16.173Z,1741122436.173 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:07:16.572Z,1741122436.572 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:07:16.572Z,1741122436.572 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:07:16.572Z,1741122436.572 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:07:16.572Z,1741122436.572 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:07:16.742Z,1741122436.742 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:07:17.242Z,1741122437.242 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:07:46.877Z,1741122466.877 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:07:16.6Z
2025-03-04T21:07:46.877Z,1741122466.877 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:07:46.878Z,1741122466.878 [speed_step_lab:Speedy] Stopped
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy](INFO): Running loop #5
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy] Running Loop=5
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:07:46.879Z,1741122466.879 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:07:47.291Z,1741122467.291 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:07:47.291Z,1741122467.291 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:07:47.291Z,1741122467.291 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:07:47.291Z,1741122467.291 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:07:47.434Z,1741122467.434 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:07:51.971Z,1741122471.971 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.904092 rad/s
2025-03-04T21:07:52.372Z,1741122472.372 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 14.985397 rad/s
2025-03-04T21:08:02.038Z,1741122482.038 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:08:06.098Z,1741122486.098 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:08:06.486Z,1741122486.486 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:08:06.947Z,1741122486.947 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:08:07.710Z,1741122487.710 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:08:08.126Z,1741122488.126 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:08:08.534Z,1741122488.534 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:08:08.936Z,1741122488.936 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:08:09.738Z,1741122489.738 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:08:10.159Z,1741122490.159 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:08:10.566Z,1741122490.566 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:08:16.207Z,1741122496.207 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:08:16.606Z,1741122496.606 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:08:17.581Z,1741122497.581 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:07:47.3Z
2025-03-04T21:08:17.592Z,1741122497.592 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:08:17.592Z,1741122497.592 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:08:17.593Z,1741122497.593 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:08:17.593Z,1741122497.593 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:08:17.593Z,1741122497.593 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:08:17.593Z,1741122497.593 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:08:17.593Z,1741122497.593 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:08:17.593Z,1741122497.593 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:08:17.594Z,1741122497.593 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:08:17.594Z,1741122497.594 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:08:17.594Z,1741122497.594 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:08:17.594Z,1741122497.594 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:08:17.983Z,1741122497.983 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:08:17.983Z,1741122497.983 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:08:17.983Z,1741122497.983 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:08:17.983Z,1741122497.983 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:08:18.146Z,1741122498.146 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:08:18.679Z,1741122498.679 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:08:22.015Z,1741122502.015 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-04T21:08:22.015Z,1741122502.015 [NAL9602] Data Fault, FailCount= 3
2025-03-04T21:08:22.015Z,1741122502.015 [NAL9602](ERROR): Data Fault
2025-03-04T21:08:22.193Z,1741122502.193 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-04T21:08:22.422Z,1741122502.422 [NAL9602](INFO): Powering down
2025-03-04T21:08:23.377Z,1741122503.377 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-04T21:08:23.377Z,1741122503.377 [NAL9602] No Fault, FailCount= 3
2025-03-04T21:08:48.292Z,1741122528.292 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:08:17.0Z
2025-03-04T21:08:48.292Z,1741122528.292 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:08:48.292Z,1741122528.292 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:08:48.292Z,1741122528.292 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:08:48.293Z,1741122528.293 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:08:48.293Z,1741122528.293 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:08:48.293Z,1741122528.293 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:08:48.293Z,1741122528.293 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:08:48.293Z,1741122528.293 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:08:48.293Z,1741122528.293 [speed_step_lab:Speedy] Stopped
2025-03-04T21:08:48.293Z,1741122528.293 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy](INFO): Running loop #6
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy] Running Loop=6
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:08:48.294Z,1741122528.294 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:08:48.691Z,1741122528.691 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:08:48.691Z,1741122528.691 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:08:48.691Z,1741122528.691 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:08:48.691Z,1741122528.691 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:08:48.847Z,1741122528.847 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:08:52.719Z,1741122532.719 [NAL9602](INFO): Powering up NAL9602
2025-03-04T21:08:53.742Z,1741122533.742 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.904092 rad/s
2025-03-04T21:08:56.586Z,1741122536.586 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 9.574003 rad/s
2025-03-04T21:08:59.018Z,1741122539.018 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 7.076437 rad/s
2025-03-04T21:09:01.842Z,1741122541.842 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:09:03.631Z,1741122543.631 [NAL9602](INFO): NAL9602 initialized
2025-03-04T21:09:06.773Z,1741122546.773 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-03-04T21:09:11.918Z,1741122551.918 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:09:17.606Z,1741122557.606 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:09:18.826Z,1741122558.826 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:09:19.078Z,1741122559.078 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:08:48.7Z
2025-03-04T21:09:19.078Z,1741122559.078 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:09:19.078Z,1741122559.078 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:09:19.079Z,1741122559.079 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:09:19.079Z,1741122559.079 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:09:19.079Z,1741122559.079 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:09:19.079Z,1741122559.079 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:09:19.079Z,1741122559.079 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:09:19.079Z,1741122559.079 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:09:19.079Z,1741122559.079 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:09:19.080Z,1741122559.080 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:09:19.080Z,1741122559.080 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:09:19.080Z,1741122559.080 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:09:19.354Z,1741122559.354 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:09:19.408Z,1741122559.408 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:09:19.408Z,1741122559.408 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:09:19.408Z,1741122559.408 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:09:19.408Z,1741122559.408 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:09:19.650Z,1741122559.650 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:09:20.070Z,1741122560.070 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:09:25.062Z,1741122565.062 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2025-03-04T21:09:25.062Z,1741122565.062 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T21:09:25.205Z,1741122565.205 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T21:09:25.629Z,1741122565.629 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T21:09:25.629Z,1741122565.629 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2025-03-04T21:09:49.693Z,1741122589.693 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:09:19.4Z
2025-03-04T21:09:49.693Z,1741122589.693 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:09:49.693Z,1741122589.693 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy] Stopped
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:09:49.694Z,1741122589.694 [speed_step_lab:Speedy](INFO): Running loop #7
2025-03-04T21:09:49.695Z,1741122589.695 [speed_step_lab:Speedy] Running Loop=7
2025-03-04T21:09:49.695Z,1741122589.695 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:09:49.695Z,1741122589.695 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:09:49.695Z,1741122589.695 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:09:49.695Z,1741122589.695 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:09:49.695Z,1741122589.695 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:09:49.695Z,1741122589.695 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:09:50.105Z,1741122590.105 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:09:50.105Z,1741122590.105 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:09:50.105Z,1741122590.105 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:09:50.106Z,1741122590.106 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:09:50.248Z,1741122590.248 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:09:54.382Z,1741122594.382 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 4.578871 rad/s
2025-03-04T21:09:59.614Z,1741122599.614 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 7.492699 rad/s
2025-03-04T21:10:07.703Z,1741122607.703 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:10:08.118Z,1741122608.118 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:10:08.490Z,1741122608.490 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:10:12.142Z,1741122612.142 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:10:12.542Z,1741122612.542 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:10:12.964Z,1741122612.964 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:10:13.395Z,1741122613.395 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:10:13.778Z,1741122613.778 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:10:14.574Z,1741122614.574 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:10:17.014Z,1741122617.014 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:10:20.395Z,1741122620.395 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:09:50.1Z
2025-03-04T21:10:20.395Z,1741122620.395 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:10:20.395Z,1741122620.395 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:10:20.396Z,1741122620.396 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:10:20.397Z,1741122620.397 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:10:20.811Z,1741122620.811 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:10:20.811Z,1741122620.811 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:10:20.811Z,1741122620.811 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:10:20.811Z,1741122620.811 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:10:20.982Z,1741122620.982 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:10:21.482Z,1741122621.482 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:10:51.116Z,1741122651.116 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:10:20.8Z
2025-03-04T21:10:51.116Z,1741122651.116 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:10:51.116Z,1741122651.116 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:10:51.116Z,1741122651.116 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:10:51.116Z,1741122651.116 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:10:51.153Z,1741122651.153 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:10:51.153Z,1741122651.153 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:10:51.153Z,1741122651.153 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:10:51.153Z,1741122651.153 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:10:51.153Z,1741122651.153 [speed_step_lab:Speedy] Stopped
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy](INFO): Running loop #8
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy] Running Loop=8
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:10:51.154Z,1741122651.154 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:10:51.503Z,1741122651.503 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:10:51.503Z,1741122651.503 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:10:51.503Z,1741122651.503 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:10:51.503Z,1741122651.503 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:10:51.672Z,1741122651.672 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:11:03.026Z,1741122663.026 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:11:03.362Z,1741122663.362 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-03-04T21:11:03.362Z,1741122663.362 [ThrusterHE](INFO): Powering down
2025-03-04T21:11:04.202Z,1741122664.202 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-03-04T21:11:04.322Z,1741122664.322 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-03-04T21:11:09.870Z,1741122669.870 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:11:14.758Z,1741122674.758 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 8.741482 rad/s
2025-03-04T21:11:15.174Z,1741122675.174 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 8.325220 rad/s
2025-03-04T21:11:15.590Z,1741122675.590 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 7.908959 rad/s
2025-03-04T21:11:18.398Z,1741122678.398 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.660176 rad/s
2025-03-04T21:11:21.763Z,1741122681.763 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:11:21.839Z,1741122681.839 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:10:51.5Z
2025-03-04T21:11:21.839Z,1741122681.839 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:11:21.839Z,1741122681.839 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:11:21.839Z,1741122681.839 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:11:21.840Z,1741122681.840 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:11:22.223Z,1741122682.223 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:11:22.224Z,1741122682.224 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:11:22.224Z,1741122682.224 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:11:22.224Z,1741122682.224 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:11:22.473Z,1741122682.473 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:11:22.886Z,1741122682.886 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:11:52.517Z,1741122712.517 [speed_step_lab:Speedy:Off:C.Wait](INFO): Timed out from 2025-03-04T21:11:22.2Z
2025-03-04T21:11:52.517Z,1741122712.517 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:11:52.517Z,1741122712.517 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy:Off](INFO): Completed speed_step_lab:Speedy:Off
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy](INFO): Completed speed_step_lab:Speedy
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy] Stopped
2025-03-04T21:11:52.518Z,1741122712.518 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy](INFO): Running loop #9
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy] Running Loop=9
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy](DEBUG): Aggregate::initialize speed_step_lab:Speedy
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy:On] Running Loop=1
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy:On](DEBUG): Aggregate::initialize speed_step_lab:Speedy:On
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy:On:A.SetSpeed] Running Loop=1
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:11:52.519Z,1741122712.519 [speed_step_lab:Speedy:On:B] Running Loop=1
2025-03-04T21:11:52.905Z,1741122712.905 [speed_step_lab:Speedy:On:B](IMPORTANT): Thruster On.
2025-03-04T21:11:52.905Z,1741122712.905 [speed_step_lab:Speedy:On:B] Stopped
2025-03-04T21:11:52.905Z,1741122712.905 [speed_step_lab:Speedy:On:C.Wait] Running Loop=1
2025-03-04T21:11:52.905Z,1741122712.905 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:11:53.065Z,1741122713.065 [Reporter](INFO): SpeedControl.speedCmd 0.200000 m/s
2025-03-04T21:11:57.178Z,1741122717.178 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 3.746349 rad/s
2025-03-04T21:11:57.595Z,1741122717.595 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 12.904092 rad/s
2025-03-04T21:12:05.275Z,1741122725.275 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.660176 rad/s
2025-03-04T21:12:10.506Z,1741122730.506 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:12:10.910Z,1741122730.910 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:12:13.746Z,1741122733.746 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:12:14.162Z,1741122734.162 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:12:14.558Z,1741122734.558 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:12:14.970Z,1741122734.970 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:12:15.786Z,1741122735.786 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:12:16.202Z,1741122736.202 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:12:16.574Z,1741122736.574 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:12:16.990Z,1741122736.990 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:12:17.383Z,1741122737.383 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:12:18.166Z,1741122738.166 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 6.243916 rad/s
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On:C.Wait](INFO): Timed out from 2025-03-04T21:11:52.9Z
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On:C.Wait] Stopped
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On](INFO): Completed speed_step_lab:Speedy:On
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On] Stopped
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:On
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On:A.SetSpeed] Stopped
2025-03-04T21:12:23.219Z,1741122743.219 [speed_step_lab:Speedy:On:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:12:23.220Z,1741122743.220 [speed_step_lab:Speedy:Off] Running Loop=1
2025-03-04T21:12:23.220Z,1741122743.220 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::initialize speed_step_lab:Speedy:Off
2025-03-04T21:12:23.220Z,1741122743.220 [speed_step_lab:Speedy:Off:A.SetSpeed] Running Loop=1
2025-03-04T21:12:23.220Z,1741122743.220 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Initialize.
2025-03-04T21:12:23.220Z,1741122743.220 [speed_step_lab:Speedy:Off:B] Running Loop=1
2025-03-04T21:12:23.467Z,1741122743.467 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 5.827654 rad/s
2025-03-04T21:12:23.615Z,1741122743.615 [speed_step_lab:Speedy:Off:B](IMPORTANT): Thruster Off.
2025-03-04T21:12:23.615Z,1741122743.615 [speed_step_lab:Speedy:Off:B] Stopped
2025-03-04T21:12:23.615Z,1741122743.615 [speed_step_lab:Speedy:Off:C.Wait] Running Loop=1
2025-03-04T21:12:23.615Z,1741122743.615 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Initialize Wait Component.
2025-03-04T21:12:23.830Z,1741122743.830 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2025-03-04T21:12:24.307Z,1741122744.307 [Reporter](INFO): ThrusterHE.platform_propeller_rotation_rate 0.000000 rad/s
2025-03-04T21:12:26.050Z,1741122746.050 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2025-03-04T21:12:26.051Z,1741122746.051 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-04T21:12:26.189Z,1741122746.189 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-04T21:12:26.594Z,1741122746.594 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-04T21:12:26.594Z,1741122746.594 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2025-03-04T21:12:46.522Z,1741122766.522 [CommandExec](IMPORTANT): got command stop
2025-03-04T21:12:46.522Z,1741122766.522 [CommandExec](IMPORTANT): Scheduling is paused
2025-03-04T21:12:46.522Z,1741122766.522 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-03-04T21:12:46.652Z,1741122766.652 [MissionManager](INFO): MissionManager is completed.
2025-03-04T21:12:46.652Z,1741122766.652 [MissionManager](INFO): Uninitializing Mission speed_step_lab
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab] Stopped
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab](DEBUG): Aggregate::uninitialize speed_step_lab
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab:Speedy] Stopped
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab:Speedy](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab:Speedy:Off] Stopped
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab:Speedy:Off](DEBUG): Aggregate::uninitialize speed_step_lab:Speedy:Off
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab:Speedy:Off:A.SetSpeed] Stopped
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab:Speedy:Off:A.SetSpeed](DEBUG): Uninitialize.
2025-03-04T21:12:46.652Z,1741122766.652 [speed_step_lab:Speedy:Off:C.Wait] Stopped
2025-03-04T21:12:46.653Z,1741122766.653 [speed_step_lab:Speedy:Off:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-04T21:12:47.070Z,1741122767.070 [MissionManager](IMPORTANT): Started mission Default
2025-03-04T21:12:47.070Z,1741122767.070 [Default] Running Loop=1
2025-03-04T21:12:47.070Z,1741122767.070 [Default](DEBUG): Aggregate::initialize Default
2025-03-04T21:12:47.070Z,1741122767.070 [Default:B.GoToSurface] Running Loop=1
2025-03-04T21:12:47.070Z,1741122767.070 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-04T21:12:47.071Z,1741122767.071 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-04T21:12:47.071Z,1741122767.071 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-04T21:12:47.071Z,1741122767.071 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-04T21:12:47.072Z,1741122767.072 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-04T21:12:47.072Z,1741122767.072 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.