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.