2025-10-01T16:32:11.661Z,1759336331.661 [Supervisor](DEBUG): Initializing supervisor.
2025-10-01T16:32:11.666Z,1759336331.666 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-10-01T16:32:11.667Z,1759336331.667 [SyncHandler](INFO): Protected caller Thread ID is 2697
2025-10-01T16:32:11.667Z,1759336331.667 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-10-01T16:32:11.669Z,1759336331.669 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-10-01T16:32:11.669Z,1759336331.669 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2698
2025-10-01T16:32:11.673Z,1759336331.673 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-10-01T16:32:11.694Z,1759336331.694 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-10-01T16:32:11.695Z,1759336331.695 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-10-01T16:32:11.695Z,1759336331.695 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2699
2025-10-01T16:32:11.699Z,1759336331.699 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-10-01T16:32:11.700Z,1759336331.700 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-10-01T16:32:11.701Z,1759336331.701 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2700
2025-10-01T16:32:11.703Z,1759336331.703 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-10-01T16:32:11.704Z,1759336331.704 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-10-01T16:32:11.704Z,1759336331.704 [logger ThreadHandler](INFO): Protected caller Thread ID is 2701
2025-10-01T16:32:11.708Z,1759336331.708 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-10-01T16:32:11.709Z,1759336331.709 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-10-01T16:32:11.710Z,1759336331.710 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-10-01T16:32:11.817Z,1759336331.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-10-01T16:32:11.818Z,1759336331.818 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-10-01T16:32:12.057Z,1759336332.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-10-01T16:32:12.058Z,1759336332.058 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-10-01T16:32:12.328Z,1759336332.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-10-01T16:32:12.329Z,1759336332.329 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-10-01T16:32:12.446Z,1759336332.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-10-01T16:32:12.447Z,1759336332.447 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-10-01T16:32:13.205Z,1759336333.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-10-01T16:32:13.206Z,1759336333.206 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-10-01T16:32:13.743Z,1759336333.743 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-10-01T16:32:13.744Z,1759336333.744 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-10-01T16:32:14.286Z,1759336334.286 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-10-01T16:32:14.286Z,1759336334.286 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-10-01T16:32:14.723Z,1759336334.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-10-01T16:32:14.724Z,1759336334.724 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-10-01T16:32:15.079Z,1759336335.079 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-10-01T16:32:15.080Z,1759336335.080 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-10-01T16:32:15.475Z,1759336335.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-10-01T16:32:15.475Z,1759336335.475 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-10-01T16:32:15.719Z,1759336335.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-10-01T16:32:15.720Z,1759336335.720 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-10-01T16:32:15.888Z,1759336335.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-10-01T16:32:15.888Z,1759336335.888 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-10-01T16:32:16.002Z,1759336336.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-10-01T16:32:16.003Z,1759336336.003 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-10-01T16:32:16.095Z,1759336336.095 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-10-01T16:32:16.643Z,1759336336.643 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-10-01T16:32:16.643Z,1759336336.643 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-10-01T16:32:17.062Z,1759336337.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-10-01T16:32:17.064Z,1759336337.064 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-10-01T16:32:17.065Z,1759336337.065 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-10-01T16:32:17.160Z,1759336337.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-10-01T16:32:17.441Z,1759336337.441 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-10-01T16:32:17.442Z,1759336337.442 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-10-01T16:32:17.537Z,1759336337.537 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-10-01T16:32:17.716Z,1759336337.716 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-10-01T16:32:17.828Z,1759336337.828 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-10-01T16:32:17.948Z,1759336337.948 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-10-01T16:32:18.071Z,1759336338.071 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-10-01T16:32:18.176Z,1759336338.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-10-01T16:32:18.344Z,1759336338.344 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-10-01T16:32:18.452Z,1759336338.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-10-01T16:32:18.548Z,1759336338.548 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-10-01T16:32:18.656Z,1759336338.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-10-01T16:32:18.755Z,1759336338.755 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2025-10-01T16:32:18.756Z,1759336338.756 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-10-01T16:32:18.765Z,1759336338.765 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-10-01T16:32:18.944Z,1759336338.944 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-10-01T16:32:18.945Z,1759336338.945 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-10-01T16:32:19.112Z,1759336339.112 [BuoyancyServo] Loaded
2025-10-01T16:32:19.113Z,1759336339.113 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-10-01T16:32:19.136Z,1759336339.136 [ElevatorServo] Loaded
2025-10-01T16:32:19.137Z,1759336339.137 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-10-01T16:32:19.160Z,1759336339.160 [MassServo] Loaded
2025-10-01T16:32:19.160Z,1759336339.160 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-10-01T16:32:19.182Z,1759336339.182 [RudderServo] Loaded
2025-10-01T16:32:19.183Z,1759336339.183 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-10-01T16:32:19.201Z,1759336339.201 [ThrusterHE] Loaded
2025-10-01T16:32:19.201Z,1759336339.201 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-10-01T16:32:19.201Z,1759336339.201 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-10-01T16:32:19.202Z,1759336339.202 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-10-01T16:32:19.364Z,1759336339.364 [SBIT](DEBUG): Construct Startup Built In Test.
2025-10-01T16:32:19.379Z,1759336339.379 [SBIT] Loaded
2025-10-01T16:32:19.380Z,1759336339.380 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-10-01T16:32:19.382Z,1759336339.382 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-10-01T16:32:19.404Z,1759336339.404 [IBIT] Loaded
2025-10-01T16:32:19.404Z,1759336339.404 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-10-01T16:32:19.409Z,1759336339.409 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-10-01T16:32:19.610Z,1759336339.610 [CBIT] Loaded
2025-10-01T16:32:19.610Z,1759336339.610 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-10-01T16:32:19.641Z,1759336339.641 [GFScanner] Loaded
2025-10-01T16:32:19.642Z,1759336339.642 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-10-01T16:32:19.642Z,1759336339.642 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-10-01T16:32:19.643Z,1759336339.643 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-10-01T16:32:19.817Z,1759336339.817 [CTD_Seabird] Loaded
2025-10-01T16:32:19.817Z,1759336339.817 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-10-01T16:32:19.818Z,1759336339.818 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406874E0
2025-10-01T16:32:19.818Z,1759336339.818 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2789
2025-10-01T16:32:19.854Z,1759336339.854 [ESPComponent] Loaded
2025-10-01T16:32:19.854Z,1759336339.854 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-10-01T16:32:19.877Z,1759336339.877 [PAR_Licor] Loaded
2025-10-01T16:32:19.877Z,1759336339.877 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-10-01T16:32:19.878Z,1759336339.878 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-10-01T16:32:19.879Z,1759336339.879 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-10-01T16:32:19.931Z,1759336339.931 [DepthRateCalculator] Loaded
2025-10-01T16:32:19.931Z,1759336339.931 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-10-01T16:32:19.936Z,1759336339.936 [PitchRateCalculator] Loaded
2025-10-01T16:32:19.937Z,1759336339.937 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-10-01T16:32:19.947Z,1759336339.947 [SpeedCalculator] Loaded
2025-10-01T16:32:19.948Z,1759336339.948 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-10-01T16:32:19.952Z,1759336339.952 [YawRateCalculator] Loaded
2025-10-01T16:32:19.953Z,1759336339.953 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-10-01T16:32:19.972Z,1759336339.972 [ElevatorOffsetCalculator] Loaded
2025-10-01T16:32:19.973Z,1759336339.973 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-10-01T16:32:19.973Z,1759336339.973 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-10-01T16:32:19.974Z,1759336339.974 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-10-01T16:32:20.111Z,1759336340.111 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-10-01T16:32:20.111Z,1759336340.111 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-10-01T16:32:20.140Z,1759336340.140 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-10-01T16:32:20.141Z,1759336340.141 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-10-01T16:32:20.256Z,1759336340.256 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-10-01T16:32:20.256Z,1759336340.256 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-10-01T16:32:20.270Z,1759336340.270 [NavChart] Loaded
2025-10-01T16:32:20.271Z,1759336340.271 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-10-01T16:32:20.276Z,1759336340.276 [UniversalFixResidualReporter] Loaded
2025-10-01T16:32:20.277Z,1759336340.277 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-10-01T16:32:20.277Z,1759336340.277 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-10-01T16:32:20.278Z,1759336340.278 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-10-01T16:32:20.763Z,1759336340.763 [AHRS_M2] Loaded
2025-10-01T16:32:20.763Z,1759336340.763 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-10-01T16:32:20.802Z,1759336340.802 [BackseatComponent] Loaded
2025-10-01T16:32:20.802Z,1759336340.802 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-10-01T16:32:20.803Z,1759336340.803 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0
2025-10-01T16:32:20.804Z,1759336340.804 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2790
2025-10-01T16:32:20.807Z,1759336340.807 [LcmUniversalReporter] Loaded
2025-10-01T16:32:20.807Z,1759336340.807 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-10-01T16:32:22.018Z,1759336342.018 [BPC1] Loaded
2025-10-01T16:32:22.018Z,1759336342.018 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-10-01T16:32:22.122Z,1759336342.122 [DAT] Loaded
2025-10-01T16:32:22.123Z,1759336342.123 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-10-01T16:32:22.124Z,1759336342.124 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0
2025-10-01T16:32:22.124Z,1759336342.124 [DAT ThreadHandler](INFO): Protected caller Thread ID is 2791
2025-10-01T16:32:22.200Z,1759336342.200 [DataOverHttps] Loaded
2025-10-01T16:32:22.200Z,1759336342.200 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-10-01T16:32:22.201Z,1759336342.201 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0
2025-10-01T16:32:22.201Z,1759336342.201 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2792
2025-10-01T16:32:22.225Z,1759336342.225 [Depth_Keller] Loaded
2025-10-01T16:32:22.225Z,1759336342.225 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-10-01T16:32:22.231Z,1759336342.231 [DropWeight] Loaded
2025-10-01T16:32:22.231Z,1759336342.231 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-10-01T16:32:22.295Z,1759336342.295 [NAL9602] Loaded
2025-10-01T16:32:22.296Z,1759336342.296 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-10-01T16:32:22.322Z,1759336342.322 [Onboard] Loaded
2025-10-01T16:32:22.322Z,1759336342.322 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-10-01T16:32:22.323Z,1759336342.323 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0
2025-10-01T16:32:22.324Z,1759336342.324 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2793
2025-10-01T16:32:22.330Z,1759336342.330 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2025-10-01T16:32:22.344Z,1759336342.344 [PowerOnly] Loaded
2025-10-01T16:32:22.344Z,1759336342.344 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-10-01T16:32:22.358Z,1759336342.358 [Power24vConverter] Loaded
2025-10-01T16:32:22.359Z,1759336342.359 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-10-01T16:32:22.375Z,1759336342.375 [Radio_Surface] Loaded
2025-10-01T16:32:22.375Z,1759336342.375 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-10-01T16:32:22.376Z,1759336342.376 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B154E0
2025-10-01T16:32:22.377Z,1759336342.377 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2794
2025-10-01T16:32:22.393Z,1759336342.393 [Sonardyne_Nano] Loaded
2025-10-01T16:32:22.393Z,1759336342.393 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-10-01T16:32:22.394Z,1759336342.394 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-10-01T16:32:22.394Z,1759336342.394 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-10-01T16:32:22.455Z,1759336342.455 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-10-01T16:32:22.455Z,1759336342.455 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-10-01T16:32:22.511Z,1759336342.511 [VerticalControl](DEBUG): Construct VerticalControl.
2025-10-01T16:32:22.564Z,1759336342.564 [VerticalControl] Loaded
2025-10-01T16:32:22.564Z,1759336342.564 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-10-01T16:32:22.567Z,1759336342.567 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-10-01T16:32:22.611Z,1759336342.611 [HorizontalControl] Loaded
2025-10-01T16:32:22.612Z,1759336342.612 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-10-01T16:32:22.614Z,1759336342.614 [SpeedControl](DEBUG): Construct SpeedControl.
2025-10-01T16:32:22.616Z,1759336342.616 [SpeedControl] Loaded
2025-10-01T16:32:22.616Z,1759336342.616 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-10-01T16:32:22.619Z,1759336342.619 [LoopControl](DEBUG): Construct LoopControl.
2025-10-01T16:32:22.620Z,1759336342.620 [LoopControl] Loaded
2025-10-01T16:32:22.620Z,1759336342.620 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-10-01T16:32:22.620Z,1759336342.620 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-10-01T16:32:22.621Z,1759336342.621 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-10-01T16:32:22.631Z,1759336342.631 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-10-01T16:32:22.632Z,1759336342.632 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-10-01T16:32:22.985Z,1759336342.985 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-10-01T16:32:22.992Z,1759336342.992 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-10-01T16:32:22.995Z,1759336342.995 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-10-01T16:32:23.006Z,1759336343.006 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-10-01T16:32:23.007Z,1759336343.007 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C3D4E0
2025-10-01T16:32:23.008Z,1759336343.008 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2795
2025-10-01T16:32:23.012Z,1759336343.012 [Supervisor](INFO): Main Thread ID is 478
2025-10-01T16:32:23.012Z,1759336343.012 [Supervisor](DEBUG): Running supervisor.
2025-10-01T16:32:23.013Z,1759336343.013 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2796
2025-10-01T16:32:23.013Z,1759336343.013 [CommandExec](INFO): Initializing the command executive.
2025-10-01T16:32:23.015Z,1759336343.015 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2797
2025-10-01T16:32:23.017Z,1759336343.017 [controlThread ThreadHandler](INFO): Handler Thread ID is 2798
2025-10-01T16:32:23.017Z,1759336343.017 [controlThread](DEBUG): Initializing ControlThread
2025-10-01T16:32:23.019Z,1759336343.019 [SBIT](INFO): Initialize SBIT Component.
2025-10-01T16:32:23.020Z,1759336343.020 [SBIT](IMPORTANT): git: 2025-09-29-1-g40a8d3ac0
2025-10-01T16:32:23.020Z,1759336343.020 [SBIT](INFO): git hash: 40a8d3ac0b5b7c3327208f41095fc66196e8acd5
2025-10-01T16:32:23.020Z,1759336343.020 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-10-01T16:32:23.022Z,1759336343.022 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-10-01T16:32:23.023Z,1759336343.023 [SBIT](INFO): Beginning SBIT in 143.000000 seconds.
2025-10-01T16:32:23.023Z,1759336343.023 [IBIT](INFO): Initialize IBIT Component.
2025-10-01T16:32:23.024Z,1759336343.024 [CBIT](DEBUG): Initialize CBIT Component.
2025-10-01T16:32:23.025Z,1759336343.025 [logger ThreadHandler](INFO): Handler Thread ID is 2799
2025-10-01T16:32:23.038Z,1759336343.038 [CBIT](DEBUG): Initialized mux pins.
2025-10-01T16:32:23.038Z,1759336343.038 [CBIT](DEBUG): Initializing the watchdog timer.
2025-10-01T16:32:23.051Z,1759336343.051 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2800
2025-10-01T16:32:23.051Z,1759336343.051 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-10-01T16:32:23.056Z,1759336343.056 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2802
2025-10-01T16:32:23.062Z,1759336343.062 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-10-01T16:32:23.063Z,1759336343.063 [CBIT](DEBUG): Initializing heartbeat.
2025-10-01T16:32:23.064Z,1759336343.064 [DAT ThreadHandler](INFO): Handler Thread ID is 2803
2025-10-01T16:32:23.064Z,1759336343.064 [DAT](INFO): Powering up
2025-10-01T16:32:23.065Z,1759336343.065 [DAT](DEBUG): Initializing DAT.
2025-10-01T16:32:23.068Z,1759336343.068 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2805
2025-10-01T16:32:23.069Z,1759336343.069 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-10-01T16:32:23.091Z,1759336343.091 [Onboard ThreadHandler](INFO): Handler Thread ID is 2806
2025-10-01T16:32:23.108Z,1759336343.108 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2807
2025-10-01T16:32:23.128Z,1759336343.128 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2808
2025-10-01T16:32:23.130Z,1759336343.130 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-10-01T16:32:23.131Z,1759336343.131 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-10-01T16:32:23.131Z,1759336343.131 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-10-01T16:32:23.131Z,1759336343.131 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-10-01T16:32:23.131Z,1759336343.131 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-10-01T16:32:23.131Z,1759336343.131 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-10-01T16:32:23.132Z,1759336343.132 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-10-01T16:32:23.132Z,1759336343.132 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-10-01T16:32:23.134Z,1759336343.134 [CBIT](DEBUG): Deactivating emergency mode.
2025-10-01T16:32:23.174Z,1759336343.174 [CBIT](DEBUG): Backplane powered.
2025-10-01T16:32:23.175Z,1759336343.175 [GFScanner](DEBUG): Initializing GFScanner
2025-10-01T16:32:23.175Z,1759336343.175 [GFScanner](DEBUG): Deactivating GF circuits.
2025-10-01T16:32:23.187Z,1759336343.187 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-10-01T16:32:23.187Z,1759336343.187 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-10-01T16:32:23.187Z,1759336343.187 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-10-01T16:32:23.188Z,1759336343.188 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-10-01T16:32:23.188Z,1759336343.188 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-10-01T16:32:23.189Z,1759336343.189 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-10-01T16:32:23.190Z,1759336343.190 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-10-01T16:32:23.201Z,1759336343.201 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-10-01T16:32:23.211Z,1759336343.211 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-10-01T16:32:23.211Z,1759336343.211 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-10-01T16:32:23.212Z,1759336343.212 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-10-01T16:32:23.213Z,1759336343.213 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-10-01T16:32:23.214Z,1759336343.214 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-10-01T16:32:23.214Z,1759336343.214 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-10-01T16:32:23.223Z,1759336343.223 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-10-01T16:32:23.309Z,1759336343.309 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-10-01T16:32:23.314Z,1759336343.314 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-10-01T16:32:23.390Z,1759336343.390 [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-10-01T16:32:23.391Z,1759336343.391 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-10-01T16:32:23.391Z,1759336343.391 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-10-01T16:32:23.392Z,1759336343.392 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-10-01T16:32:23.514Z,1759336343.514 [Radio_Surface](INFO): Powering up
2025-10-01T16:32:23.703Z,1759336343.703 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-10-01T16:32:23.725Z,1759336343.725 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-10-01T16:32:23.727Z,1759336343.727 [Default:A.Wait](DEBUG): Construct Wait.
2025-10-01T16:32:23.729Z,1759336343.729 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-10-01T16:32:23.771Z,1759336343.771 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-10-01T16:32:23.774Z,1759336343.774 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-10-01T16:32:23.796Z,1759336343.796 [Default:E.Execute](DEBUG): Construct Execute.
2025-10-01T16:32:23.815Z,1759336343.815 [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-10-01T16:32:23.820Z,1759336343.820 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-10-01T16:32:23.845Z,1759336343.845 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-10-01T16:32:23.911Z,1759336343.911 [Depth_Keller](INFO): Initializing.
2025-10-01T16:32:23.913Z,1759336343.913 [Power24vConverter](INFO): Powering up.
2025-10-01T16:32:23.914Z,1759336343.914 [Sonardyne_Nano](INFO): Initializing.
2025-10-01T16:32:23.943Z,1759336343.943 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-10-01T16:32:23.969Z,1759336343.969 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-10-01T16:32:23.975Z,1759336343.975 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-10-01T16:32:23.976Z,1759336343.976 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-10-01T16:32:23.983Z,1759336343.983 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-10-01T16:32:23.984Z,1759336343.984 [MassServo](DEBUG): Initializing EZServoServo.
2025-10-01T16:32:23.995Z,1759336343.995 [MassServo](DEBUG): Initializing MassServo.
2025-10-01T16:32:23.995Z,1759336343.995 [RudderServo](DEBUG): Initializing EZServoServo.
2025-10-01T16:32:24.003Z,1759336344.003 [RudderServo](DEBUG): Initializing RudderServo.
2025-10-01T16:32:24.003Z,1759336344.003 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-10-01T16:32:24.011Z,1759336344.011 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-10-01T16:32:24.288Z,1759336344.288 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-10-01T16:32:24.288Z,1759336344.288 [DropWeight] Hardware Fault, FailCount= 1
2025-10-01T16:32:24.288Z,1759336344.288 [DropWeight](ERROR): Hardware Fault
2025-10-01T16:32:24.289Z,1759336344.289 [PowerOnly](INFO): Powering up loadControl
2025-10-01T16:32:24.336Z,1759336344.336 [CommandExec](FAULT): Scheduling is paused
2025-10-01T16:32:24.337Z,1759336344.337 [CBIT](INFO): Critical error at 20251001T163224
2025-10-01T16:32:24.337Z,1759336344.337 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-10-01T16:32:24.347Z,1759336344.347 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-10-01T16:32:24.348Z,1759336344.348 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-10-01T16:32:24.663Z,1759336344.663 [CBIT](INFO): Critical error at 20251001T163224
2025-10-01T16:32:25.854Z,1759336345.854 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-10-01T16:32:27.140Z,1759336347.140 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-10-01T16:32:29.719Z,1759336349.719 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-10-01T16:32:35.171Z,1759336355.171 [DAT](INFO): DAT read:
2025-10-01T16:32:35.172Z,1759336355.172 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-10-01T16:32:37.187Z,1759336357.187 [DAT](INFO): DAT read: MF Frequency Band
2025-10-01T16:32:37.189Z,1759336357.189 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-10-01T16:32:37.189Z,1759336357.189 [DAT](INFO): DAT read: Oct 1 2025 16:32:31
2025-10-01T16:32:38.196Z,1759336358.196 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-10-01T16:32:38.197Z,1759336358.197 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2025-10-01T16:32:38.197Z,1759336358.197 [DAT](INFO): commRate: 1200
2025-10-01T16:32:40.262Z,1759336360.262 [DAT](INFO): entering command mode
2025-10-01T16:32:40.463Z,1759336360.463 [DAT](INFO): DAT read:
2025-10-01T16:32:40.464Z,1759336360.464 [DAT](INFO): DAT read: user:1>
2025-10-01T16:32:40.464Z,1759336360.464 [DAT](INFO): setting verbose to 3
2025-10-01T16:32:40.715Z,1759336360.715 [DAT](INFO): DAT read: user:1>
2025-10-01T16:32:40.716Z,1759336360.716 [DAT](INFO): DAT read: Verbose | 3
2025-10-01T16:32:40.716Z,1759336360.716 [DAT](INFO): set verbose to 3
2025-10-01T16:32:40.717Z,1759336360.717 [DAT](INFO): setting DatVerbose to 27440
2025-10-01T16:32:40.967Z,1759336360.967 [DAT](INFO): DAT read: user:2>
2025-10-01T16:32:40.968Z,1759336360.968 [DAT](INFO): DAT read: DatVerbose | 27440
2025-10-01T16:32:40.969Z,1759336360.969 [DAT](INFO): set DatVerbose to 27440
2025-10-01T16:32:40.969Z,1759336360.969 [DAT](INFO): setting transmit power to 8
2025-10-01T16:32:41.219Z,1759336361.219 [DAT](INFO): DAT read: user:3>
2025-10-01T16:32:41.220Z,1759336361.220 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-10-01T16:32:41.220Z,1759336361.220 [DAT](INFO): set transmit power to 8
2025-10-01T16:32:41.221Z,1759336361.221 [DAT](INFO): setting local address to 5
2025-10-01T16:32:41.471Z,1759336361.471 [DAT](INFO): DAT read: user:4>
2025-10-01T16:32:41.472Z,1759336361.472 [DAT](INFO): DAT read: LocalAddr | 5
2025-10-01T16:32:41.472Z,1759336361.472 [DAT](INFO): set local address to 5
2025-10-01T16:32:41.473Z,1759336361.473 [DAT](INFO): Setting time to: 16:32:41 And date to:10/1/2025
2025-10-01T16:32:41.723Z,1759336361.723 [DAT](INFO): DAT read: user:5>
2025-10-01T16:32:41.724Z,1759336361.724 [DAT](INFO): DAT read: Wed Oct 1, 2025 16:32:41
2025-10-01T16:32:41.724Z,1759336361.724 [DAT](INFO): Local DAT time set to Wed Oct 1, 2025 16:32:41
2025-10-01T16:32:52.524Z,1759336372.524 [NAL9602](INFO): Powering up NAL9602
2025-10-01T16:33:03.429Z,1759336383.429 [NAL9602](INFO): NAL9602 initialized
2025-10-01T16:34:34.821Z,1759336474.821 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005231
2025-10-01T16:34:46.485Z,1759336486.485 [SBIT](IMPORTANT): Beginning Startup BIT
2025-10-01T16:34:46.489Z,1759336486.489 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-10-01T16:34:50.984Z,1759336490.984 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006216
CHAN A1 (24V): 0.001995
CHAN A2 (12V): -0.005188
CHAN A3 (5V): -0.002992
CHAN B0 (3.3V): -0.001249
CHAN B1 (3.15aV): -0.001265
CHAN B2 (3.15bV): -0.000938
CHAN B3 (GND): -0.000339
OPEN: 0.006833
Full Scale: +/- 1 mA
2025-10-01T16:35:23.307Z,1759336523.307 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-10-01T16:35:23.307Z,1759336523.307 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-01T16:35:23.599Z,1759336523.599 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-01T16:35:23.975Z,1759336523.975 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-01T16:35:23.975Z,1759336523.975 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-10-01T16:35:39.972Z,1759336539.972 [SBIT](IMPORTANT): SBIT PASSED
2025-10-01T16:35:39.972Z,1759336539.972 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-10-01T16:35:39.973Z,1759336539.973 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;
2025-10-01T16:35:39.974Z,1759336539.974 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=1 bool;
2025-10-01T16:35:39.974Z,1759336539.974 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;
2025-10-01T16:35:39.974Z,1759336539.974 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere;
2025-10-01T16:35:39.974Z,1759336539.974 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;
2025-10-01T16:35:39.974Z,1759336539.974 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;
2025-10-01T16:35:39.975Z,1759336539.975 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=319.798725 cubic_centimeter;
2025-10-01T16:35:39.975Z,1759336539.975 [SBIT](IMPORTANT): VerticalControl.massDefault=30.833858 millimeter;
2025-10-01T16:35:39.975Z,1759336539.975 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;
2025-10-01T16:35:40.245Z,1759336540.245 [MissionManager](IMPORTANT): Started mission Startup
2025-10-01T16:35:40.245Z,1759336540.245 [Startup] Running Loop=1
2025-10-01T16:35:40.246Z,1759336540.246 [Startup](DEBUG): Aggregate::initialize Startup
2025-10-01T16:35:40.246Z,1759336540.246 [Startup:A.GoToSurface] Running Loop=1
2025-10-01T16:35:40.246Z,1759336540.246 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-10-01T16:35:40.252Z,1759336540.252 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-10-01T16:35:40.252Z,1759336540.252 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-10-01T16:35:40.252Z,1759336540.252 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-10-01T16:35:40.253Z,1759336540.253 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-10-01T16:35:40.253Z,1759336540.253 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-10-01T16:35:40.253Z,1759336540.253 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-10-01T16:35:40.259Z,1759336540.259 [Startup:StartupSatComms] Running Loop=1
2025-10-01T16:35:40.259Z,1759336540.259 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-10-01T16:35:40.260Z,1759336540.260 [Startup:StartupSatComms:A] Running Loop=1
2025-10-01T16:35:40.625Z,1759336540.625 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-10-01T16:36:40.417Z,1759336600.417 [Startup:StartupSatComms:A](INFO): Timed out from 2025-10-01T16:35:40.3Z
2025-10-01T16:36:40.417Z,1759336600.417 [Startup:StartupSatComms:A] Stopped
2025-10-01T16:36:40.417Z,1759336600.417 [Startup:StartupSatComms:B] Running Loop=1
2025-10-01T16:36:40.820Z,1759336600.820 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-10-01T16:36:47.402Z,1759336607.402 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20251001T161956/Courier0007.lzma
2025-10-01T16:36:48.404Z,1759336608.404 [DataOverHttps](INFO): Moved sent file to Logs/20251001T161956/Courier0007.lzma.bak
2025-10-01T16:36:48.404Z,1759336608.404 [DataOverHttps](INFO): SBD MOMSN=26088381
2025-10-01T16:37:04.310Z,1759336624.310 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20251001T163211/Courier0000.lzma
2025-10-01T16:37:05.312Z,1759336625.312 [DataOverHttps](INFO): Moved sent file to Logs/20251001T163211/Courier0000.lzma.bak
2025-10-01T16:37:05.312Z,1759336625.312 [DataOverHttps](INFO): SBD MOMSN=26088383
2025-10-01T16:37:20.981Z,1759336640.981 [DataOverHttps](INFO): Sending 950 bytes from file Logs/20251001T161956/Express0005.lzma
2025-10-01T16:37:21.980Z,1759336641.980 [DataOverHttps](INFO): Moved sent file to Logs/20251001T161956/Express0005.lzma.bak
2025-10-01T16:37:21.980Z,1759336641.980 [DataOverHttps](INFO): SBD MOMSN=26088388
2025-10-01T16:37:24.547Z,1759336644.547 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 0 revolution_per_minute
2025-10-01T16:37:24.551Z,1759336644.551 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread.
2025-10-01T16:37:24.879Z,1759336644.879 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-10-01T16:37:37.714Z,1759336657.714 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20251001T161956/Express0008.lzma
2025-10-01T16:37:38.716Z,1759336658.716 [DataOverHttps](INFO): Moved sent file to Logs/20251001T161956/Express0008.lzma.bak
2025-10-01T16:37:38.716Z,1759336658.716 [DataOverHttps](INFO): SBD MOMSN=26088433
2025-10-01T16:37:40.614Z,1759336660.614 [Startup:StartupSatComms:B](INFO): Timed out from 2025-10-01T16:36:40.4Z
2025-10-01T16:37:40.614Z,1759336660.614 [Startup:StartupSatComms:B] Stopped
2025-10-01T16:37:40.614Z,1759336660.614 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-10-01T16:37:40.614Z,1759336660.614 [Startup:StartupSatComms] Stopped
2025-10-01T16:37:40.614Z,1759336660.614 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-10-01T16:37:40.616Z,1759336660.616 [Startup](INFO): Completed Startup
2025-10-01T16:37:40.616Z,1759336660.616 [MissionManager](INFO): Startup is completed.
2025-10-01T16:37:40.616Z,1759336660.616 [MissionManager](INFO): Uninitializing Mission Startup
2025-10-01T16:37:40.616Z,1759336660.616 [Startup] Stopped
2025-10-01T16:37:40.616Z,1759336660.616 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-10-01T16:37:40.616Z,1759336660.616 [Startup:A.GoToSurface] Stopped
2025-10-01T16:37:40.616Z,1759336660.616 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-10-01T16:37:41.029Z,1759336661.029 [MissionManager](IMPORTANT): Started mission Default
2025-10-01T16:37:41.030Z,1759336661.030 [Default] Running Loop=1
2025-10-01T16:37:41.030Z,1759336661.030 [Default](DEBUG): Aggregate::initialize Default
2025-10-01T16:37:41.030Z,1759336661.030 [Default:B.GoToSurface] Running Loop=1
2025-10-01T16:37:41.030Z,1759336661.030 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-10-01T16:37:41.031Z,1759336661.031 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-10-01T16:37:41.031Z,1759336661.031 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-10-01T16:37:41.032Z,1759336661.032 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-10-01T16:37:41.032Z,1759336661.032 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-10-01T16:37:41.032Z,1759336661.032 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-10-01T16:37:41.033Z,1759336661.033 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-10-01T16:37:41.033Z,1759336661.033 [Default:A.Wait] Running Loop=1
2025-10-01T16:37:41.033Z,1759336661.033 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:37:47.132Z,1759336667.132 [DataOverHttps](IMPORTANT): SBD MTMSN=20251001T163748
2025-10-01T16:37:54.361Z,1759336674.361 [Default:A.Wait](INFO): Done Waiting.
2025-10-01T16:37:54.361Z,1759336674.361 [Default:A.Wait] Stopped
2025-10-01T16:37:54.361Z,1759336674.361 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:37:54.776Z,1759336674.776 [Default:CheckIn] Running Loop=1
2025-10-01T16:37:54.776Z,1759336674.776 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-01T16:37:54.777Z,1759336674.777 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-01T16:37:55.176Z,1759336675.176 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-10-01T16:37:55.221Z,1759336675.221 [DataOverHttps](INFO): Sending 1026 bytes from file Logs/20251001T163211/Express0001.lzma
2025-10-01T16:37:55.247Z,1759336675.247 [DataOverHttps](INFO): Received command: run Deprecated/Demo/openhouseBenchDemo.xml
2025-10-01T16:37:55.350Z,1759336675.350 [CommandExec](IMPORTANT): got command run ./Missions/Deprecated/Demo/openhouseBenchDemo.xml
2025-10-01T16:37:55.350Z,1759336675.350 [MissionManager](INFO): Loading Mission from file: ./Missions/Deprecated/Demo/openhouseBenchDemo.xml
2025-10-01T16:37:55.405Z,1759336675.405 [openhouseBenchDemo:A_Timeout:A.StopMission](DEBUG): Construct StopMission.
2025-10-01T16:37:55.406Z,1759336675.406 [openhouseBenchDemo:A.Buoyancy](DEBUG): Construct Buoyancy.
2025-10-01T16:37:55.411Z,1759336675.411 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Construct.
2025-10-01T16:37:55.414Z,1759336675.414 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Construct.
2025-10-01T16:37:55.421Z,1759336675.421 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Construct.
2025-10-01T16:37:55.428Z,1759336675.428 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Construct Wait.
2025-10-01T16:37:55.430Z,1759336675.430 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Construct.
2025-10-01T16:37:55.435Z,1759336675.435 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Construct.
2025-10-01T16:37:55.458Z,1759336675.458 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Construct.
2025-10-01T16:37:55.469Z,1759336675.469 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Construct Wait.
2025-10-01T16:37:55.481Z,1759336675.481 [MissionManager](DEBUG):
945
1
13
0
13
0.5
-13
0
-13
2025-10-01T16:37:55.484Z,1759336675.484 [CommandExec](IMPORTANT): Running ./Missions/Deprecated/Demo/openhouseBenchDemo.xml
2025-10-01T16:37:55.597Z,1759336675.597 [Default] Stopped
2025-10-01T16:37:55.597Z,1759336675.597 [Default](DEBUG): Aggregate::uninitialize Default
2025-10-01T16:37:55.597Z,1759336675.597 [Default:B.GoToSurface] Stopped
2025-10-01T16:37:55.598Z,1759336675.598 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-10-01T16:37:55.598Z,1759336675.598 [Default:CheckIn] Stopped
2025-10-01T16:37:55.598Z,1759336675.598 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-01T16:37:55.598Z,1759336675.598 [Default:CheckIn:Read_GPS] Stopped
2025-10-01T16:37:55.598Z,1759336675.598 [MissionManager](IMPORTANT): Started mission openhouseBenchDemo
2025-10-01T16:37:55.602Z,1759336675.602 [openhouseBenchDemo] Running Loop=1
2025-10-01T16:37:55.602Z,1759336675.602 [openhouseBenchDemo](DEBUG): Aggregate::initialize openhouseBenchDemo
2025-10-01T16:37:55.603Z,1759336675.603 [openhouseBenchDemo:A.Buoyancy] Running Loop=1
2025-10-01T16:37:55.603Z,1759336675.603 [openhouseBenchDemo:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN] Running Loop=1
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:37:55.604Z,1759336675.604 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:37:55.604Z,1759336675.605 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:37:55.605Z,1759336675.605 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:37:55.605Z,1759336675.605 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:37:55.605Z,1759336675.605 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:37:55.980Z,1759336675.980 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:37:55.981Z,1759336675.981 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:37:55.981Z,1759336675.981 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:37:56.221Z,1759336676.221 [DataOverHttps](INFO): Moved sent file to Logs/20251001T163211/Express0001.lzma.bak
2025-10-01T16:37:56.221Z,1759336676.221 [DataOverHttps](INFO): SBD MOMSN=26088437
2025-10-01T16:38:05.681Z,1759336685.681 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:37:55.6Z
2025-10-01T16:38:05.681Z,1759336685.681 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:38:05.681Z,1759336685.681 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:38:05.682Z,1759336685.682 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:05.682Z,1759336685.682 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:38:05.682Z,1759336685.682 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:05.682Z,1759336685.682 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:38:05.683Z,1759336685.683 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:38:05.684Z,1759336685.684 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:38:05.684Z,1759336685.684 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:38:06.096Z,1759336686.096 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:38:06.096Z,1759336686.096 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:38:06.097Z,1759336686.097 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:38:06.867Z,1759336686.867 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-10-01T16:38:15.793Z,1759336695.793 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:38:05.7Z
2025-10-01T16:38:15.793Z,1759336695.793 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:38:15.793Z,1759336695.793 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:38:15.794Z,1759336695.794 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:38:15.795Z,1759336695.795 [openhouseBenchDemo:MAIN](INFO): Running loop #2
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN] Running Loop=2
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:38:15.796Z,1759336695.796 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:38:15.797Z,1759336695.797 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:38:15.797Z,1759336695.797 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:38:24.245Z,1759336704.245 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-10-01T16:38:24.245Z,1759336704.245 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-01T16:38:24.256Z,1759336704.256 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-01T16:38:24.724Z,1759336704.724 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-01T16:38:24.725Z,1759336704.725 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-10-01T16:38:25.900Z,1759336705.900 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:38:15.8Z
2025-10-01T16:38:25.900Z,1759336705.900 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:38:25.900Z,1759336705.900 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:38:25.902Z,1759336705.902 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:38:25.903Z,1759336705.903 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:38:35.964Z,1759336715.964 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:38:25.9Z
2025-10-01T16:38:35.964Z,1759336715.964 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:38:35.965Z,1759336715.965 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:38:35.966Z,1759336715.966 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:35.966Z,1759336715.966 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:38:35.966Z,1759336715.966 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:35.966Z,1759336715.966 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:38:35.966Z,1759336715.966 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:38:35.966Z,1759336715.966 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:38:35.966Z,1759336715.966 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN](INFO): Running loop #3
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN] Running Loop=3
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:38:35.967Z,1759336715.967 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:38:35.968Z,1759336715.968 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:38:35.968Z,1759336715.968 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:38:35.968Z,1759336715.968 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:38:35.968Z,1759336715.968 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:38:35.968Z,1759336715.968 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:38:35.968Z,1759336715.968 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:38:46.069Z,1759336726.069 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:38:35.0Z
2025-10-01T16:38:46.069Z,1759336726.069 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:38:46.069Z,1759336726.069 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:38:46.070Z,1759336726.070 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:38:46.071Z,1759336726.071 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:38:46.072Z,1759336726.072 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:38:46.072Z,1759336726.072 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:38:46.072Z,1759336726.072 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:38:46.072Z,1759336726.072 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:38:56.180Z,1759336736.180 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:38:46.1Z
2025-10-01T16:38:56.180Z,1759336736.180 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:38:56.180Z,1759336736.180 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:38:56.181Z,1759336736.181 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:56.181Z,1759336736.181 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:38:56.182Z,1759336736.182 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:38:56.182Z,1759336736.182 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:38:56.182Z,1759336736.182 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:38:56.182Z,1759336736.182 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:38:56.182Z,1759336736.182 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:38:56.182Z,1759336736.182 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:38:56.182Z,1759336736.182 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:38:56.206Z,1759336736.206 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN](INFO): Running loop #4
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN] Running Loop=4
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:38:56.207Z,1759336736.207 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:38:56.208Z,1759336736.208 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:38:56.208Z,1759336736.208 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:38:56.208Z,1759336736.208 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:39:06.285Z,1759336746.285 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:38:56.2Z
2025-10-01T16:39:06.285Z,1759336746.285 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:39:06.285Z,1759336746.285 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:39:06.286Z,1759336746.286 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:06.286Z,1759336746.286 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:39:06.287Z,1759336746.287 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:39:06.288Z,1759336746.288 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:39:06.288Z,1759336746.288 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:39:06.288Z,1759336746.288 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:39:16.363Z,1759336756.363 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:39:06.3Z
2025-10-01T16:39:16.363Z,1759336756.363 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:39:16.363Z,1759336756.363 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:39:16.364Z,1759336756.364 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN](INFO): Running loop #5
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN] Running Loop=5
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:39:16.365Z,1759336756.365 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:39:16.366Z,1759336756.366 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:39:16.366Z,1759336756.366 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:39:16.366Z,1759336756.366 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:39:16.366Z,1759336756.366 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:39:26.488Z,1759336766.488 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:39:16.4Z
2025-10-01T16:39:26.488Z,1759336766.488 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:39:26.488Z,1759336766.488 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:39:26.489Z,1759336766.489 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:26.489Z,1759336766.489 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:39:26.490Z,1759336766.490 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:39:26.491Z,1759336766.491 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:39:26.491Z,1759336766.491 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:39:26.491Z,1759336766.491 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:39:26.491Z,1759336766.491 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:39:26.491Z,1759336766.491 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:39:36.561Z,1759336776.561 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:39:26.5Z
2025-10-01T16:39:36.561Z,1759336776.561 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:39:36.561Z,1759336776.561 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:39:36.562Z,1759336776.562 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:36.562Z,1759336776.562 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:39:36.562Z,1759336776.562 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:36.562Z,1759336776.562 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:39:36.562Z,1759336776.562 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN](INFO): Running loop #6
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN] Running Loop=6
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:39:36.563Z,1759336776.563 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:39:36.564Z,1759336776.564 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:39:46.701Z,1759336786.701 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:39:36.6Z
2025-10-01T16:39:46.701Z,1759336786.701 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:39:46.701Z,1759336786.701 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:39:46.703Z,1759336786.703 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:39:46.704Z,1759336786.704 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:39:56.780Z,1759336796.780 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:39:46.7Z
2025-10-01T16:39:56.780Z,1759336796.780 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:39:56.780Z,1759336796.780 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:39:56.781Z,1759336796.781 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:39:56.782Z,1759336796.782 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN](INFO): Running loop #7
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN] Running Loop=7
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:39:56.783Z,1759336796.783 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:39:56.784Z,1759336796.784 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:39:56.784Z,1759336796.784 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:39:56.784Z,1759336796.784 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:39:56.784Z,1759336796.784 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:40:06.868Z,1759336806.868 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:39:56.8Z
2025-10-01T16:40:06.868Z,1759336806.868 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:40:06.868Z,1759336806.868 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:40:06.869Z,1759336806.869 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:40:06.870Z,1759336806.870 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:06.870Z,1759336806.870 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:40:06.870Z,1759336806.870 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:40:06.870Z,1759336806.870 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:40:06.870Z,1759336806.870 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:40:06.870Z,1759336806.870 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:40:06.870Z,1759336806.870 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:40:06.871Z,1759336806.871 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:40:06.871Z,1759336806.871 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:40:16.978Z,1759336816.978 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:40:06.9Z
2025-10-01T16:40:16.978Z,1759336816.978 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:40:16.978Z,1759336816.978 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:40:16.979Z,1759336816.979 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:16.979Z,1759336816.979 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:40:16.979Z,1759336816.979 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:16.979Z,1759336816.979 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:40:16.979Z,1759336816.979 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:40:16.979Z,1759336816.979 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN](INFO): Running loop #8
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN] Running Loop=8
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:16.980Z,1759336816.980 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:40:16.981Z,1759336816.981 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:40:16.981Z,1759336816.981 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:40:16.981Z,1759336816.981 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:40:16.981Z,1759336816.981 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:40:16.981Z,1759336816.981 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:40:16.981Z,1759336816.981 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:40:16.981Z,1759336816.981 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:40:27.088Z,1759336827.088 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:40:16.0Z
2025-10-01T16:40:27.088Z,1759336827.088 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:40:27.088Z,1759336827.088 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:40:27.090Z,1759336827.090 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:27.090Z,1759336827.090 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:40:27.090Z,1759336827.090 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:27.090Z,1759336827.090 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:40:27.090Z,1759336827.090 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:40:27.090Z,1759336827.090 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:40:27.090Z,1759336827.090 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:40:27.091Z,1759336827.091 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:40:37.191Z,1759336837.191 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:40:27.1Z
2025-10-01T16:40:37.192Z,1759336837.192 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:40:37.192Z,1759336837.192 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:40:37.193Z,1759336837.193 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:40:37.194Z,1759336837.194 [openhouseBenchDemo:MAIN](INFO): Running loop #9
2025-10-01T16:40:37.194Z,1759336837.194 [openhouseBenchDemo:MAIN] Running Loop=9
2025-10-01T16:40:37.194Z,1759336837.194 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:40:37.194Z,1759336837.194 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:40:37.194Z,1759336837.194 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:37.195Z,1759336837.195 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:40:37.195Z,1759336837.195 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:40:37.195Z,1759336837.195 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:40:37.195Z,1759336837.195 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:40:37.195Z,1759336837.195 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:40:37.196Z,1759336837.196 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:40:37.196Z,1759336837.196 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:40:37.196Z,1759336837.196 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:40:47.264Z,1759336847.264 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:40:37.2Z
2025-10-01T16:40:47.264Z,1759336847.264 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:40:47.264Z,1759336847.264 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:40:47.265Z,1759336847.265 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:47.265Z,1759336847.265 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:40:47.265Z,1759336847.265 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:47.265Z,1759336847.265 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:40:47.265Z,1759336847.265 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:40:47.266Z,1759336847.266 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:40:47.267Z,1759336847.267 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:40:47.267Z,1759336847.267 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:40:47.267Z,1759336847.267 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:40:47.267Z,1759336847.267 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:40:57.363Z,1759336857.363 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:40:47.3Z
2025-10-01T16:40:57.363Z,1759336857.363 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:40:57.363Z,1759336857.363 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:40:57.364Z,1759336857.364 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:57.364Z,1759336857.364 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:40:57.364Z,1759336857.364 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:40:57.364Z,1759336857.364 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:40:57.364Z,1759336857.364 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:40:57.364Z,1759336857.364 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:40:57.364Z,1759336857.364 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN](INFO): Running loop #10
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN] Running Loop=10
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:40:57.365Z,1759336857.365 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:40:57.366Z,1759336857.366 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:40:57.366Z,1759336857.366 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:40:57.366Z,1759336857.366 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:40:57.366Z,1759336857.366 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:40:57.366Z,1759336857.366 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:40:57.366Z,1759336857.366 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:41:07.480Z,1759336867.480 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:40:57.4Z
2025-10-01T16:41:07.480Z,1759336867.480 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:41:07.480Z,1759336867.480 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:41:07.482Z,1759336867.482 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:41:07.483Z,1759336867.483 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:41:17.581Z,1759336877.581 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:41:07.5Z
2025-10-01T16:41:17.581Z,1759336877.581 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:41:17.581Z,1759336877.581 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:41:17.582Z,1759336877.582 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN](INFO): Running loop #11
2025-10-01T16:41:17.583Z,1759336877.583 [openhouseBenchDemo:MAIN] Running Loop=11
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:41:17.584Z,1759336877.584 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:41:17.585Z,1759336877.585 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:41:25.262Z,1759336885.262 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-10-01T16:41:25.262Z,1759336885.262 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-01T16:41:25.305Z,1759336885.305 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-01T16:41:25.685Z,1759336885.685 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-01T16:41:25.685Z,1759336885.685 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-10-01T16:41:27.680Z,1759336887.680 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:41:17.6Z
2025-10-01T16:41:27.680Z,1759336887.680 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:41:27.680Z,1759336887.680 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:41:27.681Z,1759336887.681 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:41:27.682Z,1759336887.682 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:27.682Z,1759336887.682 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:41:27.682Z,1759336887.682 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:41:27.682Z,1759336887.682 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:41:27.682Z,1759336887.682 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:41:27.682Z,1759336887.682 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:41:27.682Z,1759336887.682 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:41:27.683Z,1759336887.683 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:41:27.683Z,1759336887.683 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:41:37.791Z,1759336897.791 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:41:27.7Z
2025-10-01T16:41:37.791Z,1759336897.791 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:41:37.791Z,1759336897.791 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:41:37.793Z,1759336897.793 [openhouseBenchDemo:MAIN](INFO): Running loop #12
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN] Running Loop=12
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:41:37.794Z,1759336897.794 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:41:37.795Z,1759336897.795 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:41:37.795Z,1759336897.795 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:41:37.795Z,1759336897.795 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:41:37.795Z,1759336897.795 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:41:47.893Z,1759336907.893 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:41:37.8Z
2025-10-01T16:41:47.893Z,1759336907.893 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:41:47.893Z,1759336907.893 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:41:47.894Z,1759336907.894 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:47.894Z,1759336907.894 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:41:47.894Z,1759336907.894 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:41:47.895Z,1759336907.895 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:41:47.896Z,1759336907.896 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:41:47.896Z,1759336907.896 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:41:57.988Z,1759336917.988 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:41:47.9Z
2025-10-01T16:41:57.988Z,1759336917.988 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:41:57.988Z,1759336917.988 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:41:57.990Z,1759336917.990 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:57.990Z,1759336917.990 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:41:57.990Z,1759336917.990 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:41:57.990Z,1759336917.990 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:41:57.990Z,1759336917.990 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:41:57.990Z,1759336917.990 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:41:57.990Z,1759336917.990 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:41:58.018Z,1759336918.018 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:41:58.018Z,1759336918.018 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN](INFO): Running loop #13
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN] Running Loop=13
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:41:58.019Z,1759336918.019 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:41:58.020Z,1759336918.020 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:41:58.020Z,1759336918.020 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:41:58.020Z,1759336918.020 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:41:58.020Z,1759336918.020 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:42:08.088Z,1759336928.088 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:41:58.0Z
2025-10-01T16:42:08.088Z,1759336928.088 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:42:08.088Z,1759336928.088 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:42:08.089Z,1759336928.089 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:42:08.090Z,1759336928.090 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:42:08.091Z,1759336928.091 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:42:08.091Z,1759336928.091 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:42:08.091Z,1759336928.091 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:42:08.091Z,1759336928.091 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:42:08.091Z,1759336928.091 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:42:08.091Z,1759336928.091 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:42:08.091Z,1759336928.091 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:42:18.168Z,1759336938.168 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:42:08.1Z
2025-10-01T16:42:18.168Z,1759336938.168 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:42:18.169Z,1759336938.169 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:42:18.170Z,1759336938.170 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:42:18.170Z,1759336938.170 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:42:18.170Z,1759336938.170 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:42:18.170Z,1759336938.170 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:42:18.170Z,1759336938.170 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:42:18.170Z,1759336938.170 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:42:18.175Z,1759336938.175 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:42:18.175Z,1759336938.175 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:42:18.175Z,1759336938.175 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN](INFO): Running loop #14
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN] Running Loop=14
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:42:18.176Z,1759336938.176 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:42:18.177Z,1759336938.177 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:42:18.177Z,1759336938.177 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:42:18.177Z,1759336938.177 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:42:18.177Z,1759336938.177 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:42:28.276Z,1759336948.276 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](INFO): Timed out from 2025-10-01T16:42:18.2Z
2025-10-01T16:42:28.276Z,1759336948.276 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:42:28.276Z,1759336948.276 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:42:28.277Z,1759336948.277 [openhouseBenchDemo:MAIN:positiveActuation](INFO): Completed openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:42:28.277Z,1759336948.277 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:42:28.277Z,1759336948.277 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:negativeActuation] Running Loop=1
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:42:28.278Z,1759336948.278 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:42:28.282Z,1759336948.282 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Running Loop=1
2025-10-01T16:42:28.282Z,1759336948.282 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:42:28.283Z,1759336948.283 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Running Loop=1
2025-10-01T16:42:28.283Z,1759336948.283 [openhouseBenchDemo:MAIN:negativeActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:42:28.283Z,1759336948.283 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Running Loop=1
2025-10-01T16:42:28.283Z,1759336948.283 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:42:38.371Z,1759336958.371 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](INFO): Timed out from 2025-10-01T16:42:28.3Z
2025-10-01T16:42:38.371Z,1759336958.371 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait] Stopped
2025-10-01T16:42:38.371Z,1759336958.371 [openhouseBenchDemo:MAIN:negativeActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN:negativeActuation](INFO): Completed openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN:negativeActuation] Stopped
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN:negativeActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:negativeActuation
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed] Stopped
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN:negativeActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN:negativeActuation:B.Pitch] Stopped
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN:negativeActuation:C.Point] Stopped
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN](INFO): Completed openhouseBenchDemo:MAIN
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:42:38.373Z,1759336958.373 [openhouseBenchDemo:MAIN](INFO): Running loop #15
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN] Running Loop=15
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN:positiveActuation] Running Loop=1
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::initialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Running Loop=1
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Initialize.
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Running Loop=1
2025-10-01T16:42:38.374Z,1759336958.374 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch](DEBUG): Initialize.
2025-10-01T16:42:38.375Z,1759336958.375 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Running Loop=1
2025-10-01T16:42:38.375Z,1759336958.375 [openhouseBenchDemo:MAIN:positiveActuation:C.Point](DEBUG): Initialize.
2025-10-01T16:42:38.375Z,1759336958.375 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Running Loop=1
2025-10-01T16:42:38.375Z,1759336958.375 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:42:45.047Z,1759336965.047 [CommandExec](IMPORTANT): got command stop
2025-10-01T16:42:45.047Z,1759336965.047 [CommandExec](IMPORTANT): Scheduling is paused
2025-10-01T16:42:45.048Z,1759336965.048 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-10-01T16:42:45.287Z,1759336965.287 [MissionManager](INFO): MissionManager is completed.
2025-10-01T16:42:45.287Z,1759336965.287 [MissionManager](INFO): Uninitializing Mission openhouseBenchDemo
2025-10-01T16:42:45.287Z,1759336965.287 [openhouseBenchDemo] Stopped
2025-10-01T16:42:45.287Z,1759336965.287 [openhouseBenchDemo](DEBUG): Aggregate::uninitialize openhouseBenchDemo
2025-10-01T16:42:45.287Z,1759336965.287 [openhouseBenchDemo:A.Buoyancy] Stopped
2025-10-01T16:42:45.287Z,1759336965.287 [openhouseBenchDemo:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN] Stopped
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation] Stopped
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation](DEBUG): Aggregate::uninitialize openhouseBenchDemo:MAIN:positiveActuation
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed] Stopped
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation:A.SetSpeed](DEBUG): Uninitialize.
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation:B.Pitch] Stopped
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation:C.Point] Stopped
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait] Stopped
2025-10-01T16:42:45.288Z,1759336965.288 [openhouseBenchDemo:MAIN:positiveActuation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:42:45.640Z,1759336965.640 [MissionManager](IMPORTANT): Started mission Default
2025-10-01T16:42:45.640Z,1759336965.640 [Default] Running Loop=1
2025-10-01T16:42:45.640Z,1759336965.640 [Default](DEBUG): Aggregate::initialize Default
2025-10-01T16:42:45.640Z,1759336965.640 [Default:B.GoToSurface] Running Loop=1
2025-10-01T16:42:45.640Z,1759336965.640 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-10-01T16:42:45.640Z,1759336965.640 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-10-01T16:42:45.641Z,1759336965.641 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-10-01T16:42:45.641Z,1759336965.641 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-10-01T16:42:45.641Z,1759336965.641 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-10-01T16:42:45.642Z,1759336965.642 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-10-01T16:42:45.642Z,1759336965.642 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-10-01T16:42:45.642Z,1759336965.642 [Default:A.Wait] Running Loop=1
2025-10-01T16:42:45.642Z,1759336965.642 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-10-01T16:42:50.462Z,1759336970.462 [CommandExec](IMPORTANT): got command maintain clear
2025-10-01T16:42:50.533Z,1759336970.533 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-10-01T16:42:58.735Z,1759336978.735 [Default:A.Wait](INFO): Done Waiting.
2025-10-01T16:42:58.735Z,1759336978.735 [Default:A.Wait] Stopped
2025-10-01T16:42:58.735Z,1759336978.735 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-10-01T16:42:59.020Z,1759336979.020 [Default:CheckIn] Running Loop=1
2025-10-01T16:42:59.020Z,1759336979.020 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-01T16:42:59.020Z,1759336979.020 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-01T16:43:07.040Z,1759336987.040 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-10-01T16:43:07.040Z,1759336987.040 [NAL9602] Data Fault, FailCount= 1
2025-10-01T16:43:07.040Z,1759336987.040 [NAL9602](ERROR): Data Fault
2025-10-01T16:43:07.087Z,1759336987.087 [CBIT](ERROR): Data Fault in component: NAL9602
2025-10-01T16:43:07.437Z,1759336987.437 [NAL9602](INFO): Powering down
2025-10-01T16:43:08.281Z,1759336988.281 [CBIT](INFO): Clearing failed state for component NAL9602
2025-10-01T16:43:08.281Z,1759336988.281 [NAL9602] No Fault, FailCount= 1
2025-10-01T16:43:37.740Z,1759337017.740 [NAL9602](INFO): Powering up NAL9602
2025-10-01T16:43:48.653Z,1759337028.653 [NAL9602](INFO): NAL9602 initialized
2025-10-01T16:44:26.247Z,1759337066.247 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-10-01T16:44:26.247Z,1759337066.247 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-01T16:44:26.258Z,1759337066.258 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-01T16:44:26.664Z,1759337066.664 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-01T16:44:26.664Z,1759337066.664 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-10-01T16:44:33.093Z,1759337073.093 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-10-01T16:44:43.595Z,1759337083.595 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-10-01T16:45:25.711Z,1759337125.711 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:45:56.843Z,1759337156.843 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:46:27.971Z,1759337187.971 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:46:59.095Z,1759337219.095 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:47:24.425Z,1759337244.425 [CBIT](INFO): Clearing failed state for component DropWeight
2025-10-01T16:47:24.425Z,1759337244.425 [DropWeight] No Fault, FailCount= 1
2025-10-01T16:47:27.302Z,1759337247.302 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-10-01T16:47:27.302Z,1759337247.302 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-01T16:47:27.313Z,1759337247.313 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-01T16:47:27.683Z,1759337247.683 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-01T16:47:27.683Z,1759337247.683 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-10-01T16:47:30.223Z,1759337250.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:47:33.235Z,1759337253.235 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.739563
2025-10-01T16:47:59.165Z,1759337279.165 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-10-01T16:42:59.0Z
2025-10-01T16:47:59.165Z,1759337279.165 [Default:CheckIn:Read_GPS] Stopped
2025-10-01T16:47:59.165Z,1759337279.165 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-01T16:47:59.556Z,1759337279.556 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-10-01T16:48:31.467Z,1759337311.467 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:49:02.595Z,1759337342.595 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:49:33.727Z,1759337373.727 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:50:04.851Z,1759337404.851 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-01T16:50:15.196Z,1759337415.196 [CommandExec](IMPORTANT): got command restart application
2025-10-01T16:50:16.198Z,1759337416.198 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:16.199Z,1759337416.199 [CommandExec](INFO): Uninitializing the command executive.
2025-10-01T16:50:16.199Z,1759337416.199 [CommandExec](INFO): Uninitializing the command scheduler.
2025-10-01T16:50:16.199Z,1759337416.199 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:16.346Z,1759337416.346 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2025-10-01T16:50:16.346Z,1759337416.346 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-10-01T16:50:16.347Z,1759337416.347 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:16.347Z,1759337416.347 [NavChartDb](INFO): Join timeout helper Thread ID is 2876
2025-10-01T16:50:16.651Z,1759337416.651 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:16.651Z,1759337416.651 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:16.654Z,1759337416.654 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-10-01T16:50:16.654Z,1759337416.654 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:16.655Z,1759337416.655 [Radio_Surface](INFO): Join timeout helper Thread ID is 2877
2025-10-01T16:50:17.006Z,1759337417.006 [Radio_Surface](INFO): Powering down
2025-10-01T16:50:17.007Z,1759337417.007 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:17.008Z,1759337417.008 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:17.015Z,1759337417.015 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-10-01T16:50:17.015Z,1759337417.015 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:17.016Z,1759337417.016 [Onboard](INFO): Join timeout helper Thread ID is 2878
2025-10-01T16:50:19.003Z,1759337419.003 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:19.003Z,1759337419.003 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:19.006Z,1759337419.006 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-10-01T16:50:19.006Z,1759337419.006 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:19.007Z,1759337419.007 [DataOverHttps](INFO): Join timeout helper Thread ID is 2879
2025-10-01T16:50:19.911Z,1759337419.911 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:19.911Z,1759337419.911 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:19.914Z,1759337419.914 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2025-10-01T16:50:19.914Z,1759337419.914 [DAT ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:19.915Z,1759337419.915 [DAT](INFO): Join timeout helper Thread ID is 2880
2025-10-01T16:50:19.967Z,1759337419.967 [DAT](INFO): Powering down
2025-10-01T16:50:20.039Z,1759337420.039 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:20.039Z,1759337420.039 [DAT](INFO): Powering down
2025-10-01T16:50:20.040Z,1759337420.040 [DAT ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.055Z,1759337420.055 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2025-10-01T16:50:20.055Z,1759337420.055 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.056Z,1759337420.056 [BackseatComponent](INFO): Join timeout helper Thread ID is 2881
2025-10-01T16:50:20.099Z,1759337420.099 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:20.099Z,1759337420.099 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.123Z,1759337420.123 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2025-10-01T16:50:20.123Z,1759337420.123 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.124Z,1759337420.124 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2882
2025-10-01T16:50:20.503Z,1759337420.503 [CTD_Seabird](INFO): Powering down
2025-10-01T16:50:20.518Z,1759337420.518 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:20.525Z,1759337420.525 [CTD_Seabird](INFO): Powering down
2025-10-01T16:50:20.554Z,1759337420.554 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.571Z,1759337420.571 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2025-10-01T16:50:20.571Z,1759337420.571 [logger ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.572Z,1759337420.572 [logger](INFO): Join timeout helper Thread ID is 2883
2025-10-01T16:50:20.624Z,1759337420.624 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:20.624Z,1759337420.624 [logger ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.631Z,1759337420.631 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2025-10-01T16:50:20.631Z,1759337420.631 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.632Z,1759337420.632 [CommandLine](INFO): Join timeout helper Thread ID is 2884
2025-10-01T16:50:20.699Z,1759337420.699 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:20.699Z,1759337420.699 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.711Z,1759337420.711 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2025-10-01T16:50:20.711Z,1759337420.711 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.712Z,1759337420.712 [CommandExec](INFO): Join timeout helper Thread ID is 2885
2025-10-01T16:50:20.713Z,1759337420.713 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2025-10-01T16:50:20.713Z,1759337420.713 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:20.713Z,1759337420.713 [controlThread](INFO): Join timeout helper Thread ID is 2886
2025-10-01T16:50:20.858Z,1759337420.858 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2025-10-01T16:50:20.858Z,1759337420.858 [controlThread](DEBUG): Uninitializing ControlThread
2025-10-01T16:50:20.859Z,1759337420.859 [AHRS_M2](INFO): Powering down
2025-10-01T16:50:20.939Z,1759337420.939 [NAL9602](INFO): Powering down
2025-10-01T16:50:20.940Z,1759337420.940 [Sonardyne_Nano](INFO): Powering down
2025-10-01T16:50:21.143Z,1759337421.143 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2025-10-01T16:50:21.143Z,1759337421.143 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2025-10-01T16:50:21.144Z,1759337421.144 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2025-10-01T16:50:21.144Z,1759337421.144 [MissionManager](INFO): Uninitializing Mission Default
2025-10-01T16:50:21.144Z,1759337421.144 [Default] Stopped
2025-10-01T16:50:21.145Z,1759337421.145 [Default](DEBUG): Aggregate::uninitialize Default
2025-10-01T16:50:21.145Z,1759337421.145 [Default:B.GoToSurface] Stopped
2025-10-01T16:50:21.145Z,1759337421.145 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-10-01T16:50:21.145Z,1759337421.145 [Default:CheckIn] Stopped
2025-10-01T16:50:21.145Z,1759337421.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-01T16:50:21.145Z,1759337421.145 [Default:CheckIn:Read_Iridium] Stopped
2025-10-01T16:50:21.148Z,1759337421.148 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2025-10-01T16:50:21.148Z,1759337421.148 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2025-10-01T16:50:21.149Z,1759337421.149 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2025-10-01T16:50:21.149Z,1759337421.149 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2025-10-01T16:50:21.149Z,1759337421.149 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-10-01T16:50:21.149Z,1759337421.149 [BuoyancyServo](INFO): Powering down
2025-10-01T16:50:21.162Z,1759337421.162 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-10-01T16:50:21.163Z,1759337421.163 [ElevatorServo](INFO): Powering down
2025-10-01T16:50:21.163Z,1759337421.163 [MassServo](DEBUG): Uninitialize Mass Servo.
2025-10-01T16:50:21.164Z,1759337421.164 [MassServo](INFO): Powering down
2025-10-01T16:50:21.164Z,1759337421.164 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2025-10-01T16:50:21.164Z,1759337421.164 [RudderServo](INFO): Powering down
2025-10-01T16:50:21.165Z,1759337421.165 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-10-01T16:50:21.165Z,1759337421.165 [ThrusterHE](INFO): Powering down
2025-10-01T16:50:21.166Z,1759337421.166 [SBIT](DEBUG): Uninitialize SBIT Component.
2025-10-01T16:50:21.167Z,1759337421.167 [IBIT](DEBUG): Uninitialize IBIT Component.
2025-10-01T16:50:21.167Z,1759337421.167 [CBIT](DEBUG): Uninitialize CBIT Component.
2025-10-01T16:50:21.167Z,1759337421.167 [CBIT](DEBUG): Powering off loads.
2025-10-01T16:50:21.178Z,1759337421.178 [CBIT](DEBUG): Disabling WDT.
2025-10-01T16:50:21.191Z,1759337421.191 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-10-01T16:50:21.191Z,1759337421.191 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-10-01T16:50:21.192Z,1759337421.192 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.229Z,1759337421.229 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-10-01T16:50:21.229Z,1759337421.229 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-10-01T16:50:21.246Z,1759337421.246 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.340Z,1759337421.340 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.344Z,1759337421.344 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.360Z,1759337421.360 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.376Z,1759337421.376 [DAT ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.558Z,1759337421.558 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.749Z,1759337421.749 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-10-01T16:50:21.815Z,1759337421.815 [logger ThreadHandler](INFO): Thread cancelled.