2025-03-07T01:18:41.810Z,1741310321.810 [Supervisor](DEBUG): Initializing supervisor.
2025-03-07T01:18:41.815Z,1741310321.815 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-03-07T01:18:41.816Z,1741310321.816 [SyncHandler](INFO): Protected caller Thread ID is 1267
2025-03-07T01:18:41.816Z,1741310321.816 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-03-07T01:18:41.818Z,1741310321.818 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-03-07T01:18:41.818Z,1741310321.818 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1268
2025-03-07T01:18:41.823Z,1741310321.823 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-03-07T01:18:41.842Z,1741310321.842 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-03-07T01:18:41.843Z,1741310321.843 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-03-07T01:18:41.843Z,1741310321.843 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1269
2025-03-07T01:18:41.847Z,1741310321.847 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-03-07T01:18:41.848Z,1741310321.848 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-03-07T01:18:41.849Z,1741310321.849 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1270
2025-03-07T01:18:41.851Z,1741310321.851 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-03-07T01:18:41.852Z,1741310321.852 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-03-07T01:18:41.852Z,1741310321.852 [logger ThreadHandler](INFO): Protected caller Thread ID is 1271
2025-03-07T01:18:41.856Z,1741310321.856 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-03-07T01:18:41.857Z,1741310321.857 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-03-07T01:18:41.858Z,1741310321.858 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-03-07T01:18:42.083Z,1741310322.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-03-07T01:18:42.084Z,1741310322.084 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-03-07T01:18:42.201Z,1741310322.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-03-07T01:18:42.202Z,1741310322.202 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-03-07T01:18:42.307Z,1741310322.307 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-03-07T01:18:42.308Z,1741310322.308 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-03-07T01:18:42.817Z,1741310322.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-03-07T01:18:42.818Z,1741310322.818 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-03-07T01:18:43.191Z,1741310323.191 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-03-07T01:18:43.191Z,1741310323.191 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-03-07T01:18:43.553Z,1741310323.553 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-03-07T01:18:43.554Z,1741310323.554 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-03-07T01:18:43.754Z,1741310323.754 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-03-07T01:18:43.755Z,1741310323.755 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-03-07T01:18:43.844Z,1741310323.844 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-03-07T01:18:43.934Z,1741310323.934 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-03-07T01:18:44.366Z,1741310324.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-03-07T01:18:44.366Z,1741310324.366 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-03-07T01:18:44.671Z,1741310324.671 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-03-07T01:18:44.672Z,1741310324.672 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-03-07T01:18:45.249Z,1741310325.249 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-03-07T01:18:45.250Z,1741310325.250 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-03-07T01:18:45.507Z,1741310325.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-03-07T01:18:45.508Z,1741310325.508 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-03-07T01:18:45.767Z,1741310325.767 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-03-07T01:18:45.767Z,1741310325.767 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-03-07T01:18:45.932Z,1741310325.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-03-07T01:18:45.933Z,1741310325.933 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-03-07T01:18:47.588Z,1741310327.588 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-03-07T01:18:47.589Z,1741310327.589 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2025-03-07T01:18:47.590Z,1741310327.590 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2025-03-07T01:18:47.684Z,1741310327.684 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2025-03-07T01:18:47.823Z,1741310327.823 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2025-03-07T01:18:48.104Z,1741310328.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-03-07T01:18:48.105Z,1741310328.105 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2025-03-07T01:18:48.239Z,1741310328.239 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2025-03-07T01:18:48.346Z,1741310328.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2025-03-07T01:18:48.449Z,1741310328.449 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2025-03-07T01:18:48.567Z,1741310328.567 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2025-03-07T01:18:48.661Z,1741310328.661 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2025-03-07T01:18:48.756Z,1741310328.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2025-03-07T01:18:48.859Z,1741310328.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2025-03-07T01:18:49.040Z,1741310329.040 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2025-03-07T01:18:49.040Z,1741310329.040 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-03-07T01:18:49.053Z,1741310329.053 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-03-07T01:18:49.108Z,1741310329.108 [DepthRateCalculator] Loaded
2025-03-07T01:18:49.108Z,1741310329.108 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-03-07T01:18:49.114Z,1741310329.114 [PitchRateCalculator] Loaded
2025-03-07T01:18:49.114Z,1741310329.114 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-03-07T01:18:49.125Z,1741310329.125 [SpeedCalculator] Loaded
2025-03-07T01:18:49.125Z,1741310329.125 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-03-07T01:18:49.131Z,1741310329.131 [YawRateCalculator] Loaded
2025-03-07T01:18:49.131Z,1741310329.131 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-03-07T01:18:49.153Z,1741310329.153 [ElevatorOffsetCalculator] Loaded
2025-03-07T01:18:49.153Z,1741310329.153 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-03-07T01:18:49.154Z,1741310329.154 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-03-07T01:18:49.154Z,1741310329.154 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-03-07T01:18:49.185Z,1741310329.185 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-03-07T01:18:49.185Z,1741310329.185 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-03-07T01:18:49.196Z,1741310329.196 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-03-07T01:18:49.197Z,1741310329.197 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-03-07T01:18:49.728Z,1741310329.728 [AHRS_M2] Loaded
2025-03-07T01:18:49.729Z,1741310329.729 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-03-07T01:18:49.768Z,1741310329.768 [BackseatComponent] Loaded
2025-03-07T01:18:49.768Z,1741310329.768 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-03-07T01:18:49.769Z,1741310329.769 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408754E0
2025-03-07T01:18:49.770Z,1741310329.770 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1353
2025-03-07T01:18:49.773Z,1741310329.773 [LcmUniversalReporter] Loaded
2025-03-07T01:18:49.773Z,1741310329.773 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-03-07T01:18:50.584Z,1741310330.584 [BPC1] Loaded
2025-03-07T01:18:50.584Z,1741310330.584 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-03-07T01:18:50.660Z,1741310330.660 [DataOverHttps] Loaded
2025-03-07T01:18:50.660Z,1741310330.660 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-03-07T01:18:50.661Z,1741310330.661 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408A54E0
2025-03-07T01:18:50.661Z,1741310330.661 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1354
2025-03-07T01:18:50.684Z,1741310330.684 [Depth_Keller] Loaded
2025-03-07T01:18:50.685Z,1741310330.685 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-03-07T01:18:50.690Z,1741310330.690 [DropWeight] Loaded
2025-03-07T01:18:50.690Z,1741310330.690 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-03-07T01:18:50.711Z,1741310330.711 [MultiRay] Loaded
2025-03-07T01:18:50.712Z,1741310330.712 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2025-03-07T01:18:50.777Z,1741310330.777 [NAL9602] Loaded
2025-03-07T01:18:50.777Z,1741310330.777 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-03-07T01:18:50.808Z,1741310330.808 [Onboard] Loaded
2025-03-07T01:18:50.808Z,1741310330.808 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-03-07T01:18:50.809Z,1741310330.809 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408D54E0
2025-03-07T01:18:50.809Z,1741310330.809 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1355
2025-03-07T01:18:50.815Z,1741310330.815 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2025-03-07T01:18:50.829Z,1741310330.829 [PowerOnly] Loaded
2025-03-07T01:18:50.829Z,1741310330.829 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-03-07T01:18:50.843Z,1741310330.843 [Power24vConverter] Loaded
2025-03-07T01:18:50.844Z,1741310330.844 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-03-07T01:18:50.861Z,1741310330.861 [Radio_Surface] Loaded
2025-03-07T01:18:50.861Z,1741310330.861 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-03-07T01:18:50.863Z,1741310330.863 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409054E0
2025-03-07T01:18:50.863Z,1741310330.863 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1356
2025-03-07T01:18:50.889Z,1741310330.889 [Waterlinked] Loaded
2025-03-07T01:18:50.889Z,1741310330.889 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2025-03-07T01:18:50.889Z,1741310330.889 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-03-07T01:18:50.890Z,1741310330.890 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-03-07T01:18:51.008Z,1741310331.008 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-03-07T01:18:51.008Z,1741310331.008 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-03-07T01:18:51.022Z,1741310331.022 [NavChart] Loaded
2025-03-07T01:18:51.022Z,1741310331.022 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-03-07T01:18:51.028Z,1741310331.028 [UniversalFixResidualReporter] Loaded
2025-03-07T01:18:51.028Z,1741310331.028 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-03-07T01:18:51.029Z,1741310331.029 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-03-07T01:18:51.029Z,1741310331.029 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-03-07T01:18:51.504Z,1741310331.504 [SBIT](DEBUG): Construct Startup Built In Test.
2025-03-07T01:18:51.523Z,1741310331.523 [SBIT] Loaded
2025-03-07T01:18:51.523Z,1741310331.523 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-03-07T01:18:51.526Z,1741310331.526 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-03-07T01:18:51.539Z,1741310331.539 [IBIT] Loaded
2025-03-07T01:18:51.539Z,1741310331.539 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-03-07T01:18:51.545Z,1741310331.545 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-03-07T01:18:51.626Z,1741310331.626 [CBIT] Loaded
2025-03-07T01:18:51.626Z,1741310331.626 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-03-07T01:18:51.659Z,1741310331.659 [GFScanner] Loaded
2025-03-07T01:18:51.659Z,1741310331.659 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-03-07T01:18:51.660Z,1741310331.660 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-03-07T01:18:51.660Z,1741310331.660 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-03-07T01:18:51.836Z,1741310331.836 [CTD_Seabird] Loaded
2025-03-07T01:18:51.836Z,1741310331.836 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-03-07T01:18:51.837Z,1741310331.837 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A174E0
2025-03-07T01:18:51.837Z,1741310331.837 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1357
2025-03-07T01:18:51.860Z,1741310331.860 [PAR_Licor] Loaded
2025-03-07T01:18:51.860Z,1741310331.860 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-03-07T01:18:51.908Z,1741310331.908 [WetLabsBB2FL] Loaded
2025-03-07T01:18:51.908Z,1741310331.908 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-03-07T01:18:51.909Z,1741310331.909 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2025-03-07T01:18:51.910Z,1741310331.910 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1358
2025-03-07T01:18:51.910Z,1741310331.910 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-03-07T01:18:51.911Z,1741310331.911 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-03-07T01:18:52.059Z,1741310332.059 [BuoyancyServo] Loaded
2025-03-07T01:18:52.060Z,1741310332.060 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-03-07T01:18:52.084Z,1741310332.084 [ElevatorServo] Loaded
2025-03-07T01:18:52.085Z,1741310332.085 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-03-07T01:18:52.108Z,1741310332.108 [MassServo] Loaded
2025-03-07T01:18:52.109Z,1741310332.109 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-03-07T01:18:52.132Z,1741310332.132 [RudderServo] Loaded
2025-03-07T01:18:52.132Z,1741310332.132 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-03-07T01:18:52.151Z,1741310332.151 [ThrusterHE] Loaded
2025-03-07T01:18:52.152Z,1741310332.152 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-03-07T01:18:52.152Z,1741310332.152 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-03-07T01:18:52.152Z,1741310332.152 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-03-07T01:18:52.210Z,1741310332.210 [VerticalControl](DEBUG): Construct VerticalControl.
2025-03-07T01:18:52.264Z,1741310332.264 [VerticalControl] Loaded
2025-03-07T01:18:52.264Z,1741310332.264 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-03-07T01:18:52.267Z,1741310332.267 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-03-07T01:18:52.312Z,1741310332.312 [HorizontalControl] Loaded
2025-03-07T01:18:52.313Z,1741310332.313 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-03-07T01:18:52.315Z,1741310332.315 [SpeedControl](DEBUG): Construct SpeedControl.
2025-03-07T01:18:52.317Z,1741310332.317 [SpeedControl] Loaded
2025-03-07T01:18:52.317Z,1741310332.317 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-03-07T01:18:52.320Z,1741310332.320 [LoopControl](DEBUG): Construct LoopControl.
2025-03-07T01:18:52.321Z,1741310332.321 [LoopControl] Loaded
2025-03-07T01:18:52.321Z,1741310332.321 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-03-07T01:18:52.321Z,1741310332.321 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-03-07T01:18:52.322Z,1741310332.322 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-03-07T01:18:52.468Z,1741310332.468 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-03-07T01:18:52.468Z,1741310332.468 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-03-07T01:18:52.662Z,1741310332.662 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-03-07T01:18:52.662Z,1741310332.662 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-03-07T01:18:53.040Z,1741310333.040 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-03-07T01:18:53.041Z,1741310333.041 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-03-07T01:18:53.104Z,1741310333.104 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-03-07T01:18:53.111Z,1741310333.111 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-03-07T01:18:53.114Z,1741310333.114 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-03-07T01:18:53.125Z,1741310333.125 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-03-07T01:18:53.126Z,1741310333.126 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0
2025-03-07T01:18:53.127Z,1741310333.127 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1359
2025-03-07T01:18:53.131Z,1741310333.131 [Supervisor](INFO): Main Thread ID is 830
2025-03-07T01:18:53.131Z,1741310333.131 [Supervisor](DEBUG): Running supervisor.
2025-03-07T01:18:53.132Z,1741310333.132 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1360
2025-03-07T01:18:53.132Z,1741310333.132 [CommandExec](INFO): Initializing the command executive.
2025-03-07T01:18:53.134Z,1741310333.134 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1361
2025-03-07T01:18:53.136Z,1741310333.136 [controlThread ThreadHandler](INFO): Handler Thread ID is 1362
2025-03-07T01:18:53.136Z,1741310333.136 [controlThread](DEBUG): Initializing ControlThread
2025-03-07T01:18:53.137Z,1741310333.137 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-03-07T01:18:53.138Z,1741310333.138 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-03-07T01:18:53.138Z,1741310333.138 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-03-07T01:18:53.138Z,1741310333.138 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-03-07T01:18:53.139Z,1741310333.139 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-03-07T01:18:53.145Z,1741310333.145 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-03-07T01:18:53.146Z,1741310333.146 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-03-07T01:18:53.146Z,1741310333.146 [SBIT](INFO): Initialize SBIT Component.
2025-03-07T01:18:53.147Z,1741310333.147 [SBIT](IMPORTANT): git: 2025-03-06_B-3-g06c58acc0
2025-03-07T01:18:53.147Z,1741310333.147 [SBIT](INFO): git hash: 06c58acc0c21dac1722dadabfa9aaff283a6c1e9
2025-03-07T01:18:53.147Z,1741310333.147 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-03-07T01:18:53.148Z,1741310333.148 [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-03-07T01:18:53.149Z,1741310333.149 [SBIT](INFO): Beginning SBIT in 73.000000 seconds.
2025-03-07T01:18:53.150Z,1741310333.150 [IBIT](INFO): Initialize IBIT Component.
2025-03-07T01:18:53.151Z,1741310333.151 [CBIT](DEBUG): Initialize CBIT Component.
2025-03-07T01:18:53.152Z,1741310333.152 [logger ThreadHandler](INFO): Handler Thread ID is 1363
2025-03-07T01:18:53.162Z,1741310333.162 [CBIT](DEBUG): Initialized mux pins.
2025-03-07T01:18:53.162Z,1741310333.162 [CBIT](DEBUG): Initializing the watchdog timer.
2025-03-07T01:18:53.171Z,1741310333.171 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1364
2025-03-07T01:18:53.183Z,1741310333.183 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1365
2025-03-07T01:18:53.184Z,1741310333.184 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-03-07T01:18:53.186Z,1741310333.186 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-03-07T01:18:53.187Z,1741310333.187 [CBIT](DEBUG): Initializing heartbeat.
2025-03-07T01:18:53.195Z,1741310333.195 [Onboard ThreadHandler](INFO): Handler Thread ID is 1366
2025-03-07T01:18:53.212Z,1741310333.212 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1367
2025-03-07T01:18:53.235Z,1741310333.235 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1368
2025-03-07T01:18:53.236Z,1741310333.236 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-03-07T01:18:53.240Z,1741310333.240 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1370
2025-03-07T01:18:53.243Z,1741310333.243 [WetLabsBB2FL](INFO): Powering up
2025-03-07T01:18:53.244Z,1741310333.244 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1372
2025-03-07T01:18:53.246Z,1741310333.246 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-03-07T01:18:53.246Z,1741310333.246 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-03-07T01:18:53.247Z,1741310333.247 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-03-07T01:18:53.247Z,1741310333.247 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-03-07T01:18:53.247Z,1741310333.247 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-03-07T01:18:53.247Z,1741310333.247 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-03-07T01:18:53.247Z,1741310333.247 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-03-07T01:18:53.248Z,1741310333.248 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-03-07T01:18:53.258Z,1741310333.258 [CBIT](DEBUG): Deactivating emergency mode.
2025-03-07T01:18:53.298Z,1741310333.298 [CBIT](DEBUG): Backplane powered.
2025-03-07T01:18:53.298Z,1741310333.298 [GFScanner](DEBUG): Initializing GFScanner
2025-03-07T01:18:53.298Z,1741310333.298 [GFScanner](DEBUG): Deactivating GF circuits.
2025-03-07T01:18:53.308Z,1741310333.308 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-03-07T01:18:53.309Z,1741310333.309 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-03-07T01:18:53.310Z,1741310333.310 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-03-07T01:18:53.311Z,1741310333.311 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-03-07T01:18:53.311Z,1741310333.311 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-03-07T01:18:53.312Z,1741310333.312 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-03-07T01:18:53.312Z,1741310333.312 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-03-07T01:18:53.313Z,1741310333.313 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-03-07T01:18:53.370Z,1741310333.370 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-03-07T01:18:53.387Z,1741310333.387 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-07T01:18:53.408Z,1741310333.408 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-03-07T01:18:53.409Z,1741310333.409 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-03-07T01:18:53.409Z,1741310333.409 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-03-07T01:18:53.416Z,1741310333.416 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-03-07T01:18:53.618Z,1741310333.618 [Radio_Surface](INFO): Powering up
2025-03-07T01:18:53.646Z,1741310333.646 [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-03-07T01:18:53.653Z,1741310333.653 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-03-07T01:18:53.654Z,1741310333.654 [Default:A.Wait](DEBUG): Construct Wait.
2025-03-07T01:18:53.659Z,1741310333.659 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-07T01:18:53.681Z,1741310333.681 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-07T01:18:53.684Z,1741310333.684 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-07T01:18:53.690Z,1741310333.690 [Default:E.Execute](DEBUG): Construct Execute.
2025-03-07T01:18:53.713Z,1741310333.713 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-03-07T01:18:53.718Z,1741310333.718 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,Waterlinked,PAR_Licor,Depth_Keller,PAR_Licor,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-03-07T01:18:53.725Z,1741310333.725 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-03-07T01:18:53.781Z,1741310333.781 [MultiRay](INFO): Powering up MultiRay Lights
2025-03-07T01:18:53.799Z,1741310333.799 [PowerOnly](INFO): Powering up loadControl
2025-03-07T01:18:53.819Z,1741310333.819 [Power24vConverter](INFO): Powering up.
2025-03-07T01:18:53.851Z,1741310333.851 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-03-07T01:18:53.859Z,1741310333.859 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-03-07T01:18:53.860Z,1741310333.860 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-03-07T01:18:53.866Z,1741310333.866 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-03-07T01:18:53.867Z,1741310333.867 [MassServo](DEBUG): Initializing EZServoServo.
2025-03-07T01:18:53.882Z,1741310333.882 [MassServo](DEBUG): Initializing MassServo.
2025-03-07T01:18:53.883Z,1741310333.883 [RudderServo](DEBUG): Initializing EZServoServo.
2025-03-07T01:18:53.890Z,1741310333.890 [RudderServo](DEBUG): Initializing RudderServo.
2025-03-07T01:18:53.891Z,1741310333.891 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-03-07T01:18:53.898Z,1741310333.898 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-03-07T01:18:54.161Z,1741310334.161 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2025-03-07T01:18:54.161Z,1741310334.161 [DropWeight] Hardware Fault, FailCount= 1
2025-03-07T01:18:54.161Z,1741310334.161 [DropWeight](ERROR): Hardware Fault
2025-03-07T01:18:54.209Z,1741310334.209 [CommandExec](FAULT): Scheduling is paused
2025-03-07T01:18:54.214Z,1741310334.214 [CBIT](INFO): Critical error at 20250307T011854
2025-03-07T01:18:54.214Z,1741310334.214 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-03-07T01:18:54.217Z,1741310334.217 [CBIT](ERROR): Hardware Fault in component: DropWeight
2025-03-07T01:18:54.217Z,1741310334.217 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2025-03-07T01:18:54.559Z,1741310334.559 [CBIT](INFO): Critical error at 20250307T011854
2025-03-07T01:18:55.858Z,1741310335.858 [WetLabsBB2FL](INFO): Powering down
2025-03-07T01:19:00.267Z,1741310340.267 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-03-07T01:19:20.804Z,1741310360.804 [NAL9602](INFO): Powering up NAL9602
2025-03-07T01:19:31.723Z,1741310371.723 [NAL9602](INFO): NAL9602 initialized
2025-03-07T01:19:34.638Z,1741310374.638 [Waterlinked](INFO): Powering down
2025-03-07T01:20:06.874Z,1741310406.874 [SBIT](IMPORTANT): Beginning Startup BIT
2025-03-07T01:20:06.895Z,1741310406.895 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-03-07T01:20:11.515Z,1741310411.515 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.004694
CHAN A1 (24V): 0.042717
CHAN A2 (12V): -0.004476
CHAN A3 (5V): -0.003063
CHAN B0 (3.3V): -0.001026
CHAN B1 (3.15aV): -0.001541
CHAN B2 (3.15bV): -0.000791
CHAN B3 (GND): -0.001037
OPEN: 0.004937
Full Scale: +/- 1 mA
2025-03-07T01:21:00.689Z,1741310460.689 [SBIT](IMPORTANT): SBIT PASSED
2025-03-07T01:21:00.689Z,1741310460.689 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-03-07T01:21:00.690Z,1741310460.690 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2025-03-07T01:21:00.690Z,1741310460.690 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2025-03-07T01:21:00.690Z,1741310460.690 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2025-03-07T01:21:00.690Z,1741310460.690 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;
2025-03-07T01:21:00.690Z,1741310460.690 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): MultiRay.loadAtStartup=1 bool;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=185.902950 cubic_centimeter;
2025-03-07T01:21:00.691Z,1741310460.691 [SBIT](IMPORTANT): VerticalControl.massDefault=13.432478 millimeter;
2025-03-07T01:21:01.089Z,1741310461.089 [MissionManager](IMPORTANT): Started mission Startup
2025-03-07T01:21:01.089Z,1741310461.089 [Startup] Running Loop=1
2025-03-07T01:21:01.089Z,1741310461.089 [Startup](DEBUG): Aggregate::initialize Startup
2025-03-07T01:21:01.089Z,1741310461.089 [Startup:A.GoToSurface] Running Loop=1
2025-03-07T01:21:01.089Z,1741310461.089 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-07T01:21:01.090Z,1741310461.090 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-07T01:21:01.091Z,1741310461.091 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-07T01:21:01.091Z,1741310461.091 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-07T01:21:01.091Z,1741310461.091 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-07T01:21:01.092Z,1741310461.092 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-07T01:21:01.092Z,1741310461.092 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-07T01:21:01.094Z,1741310461.094 [Startup:StartupSatComms] Running Loop=1
2025-03-07T01:21:01.094Z,1741310461.094 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-03-07T01:21:01.094Z,1741310461.094 [Startup:StartupSatComms:A] Running Loop=1
2025-03-07T01:21:01.505Z,1741310461.505 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-03-07T01:21:21.073Z,1741310481.073 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005211
2025-03-07T01:21:53.215Z,1741310513.215 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-03-07T01:21:53.215Z,1741310513.215 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-07T01:21:53.234Z,1741310513.234 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-07T01:21:53.640Z,1741310513.640 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-07T01:21:53.640Z,1741310513.640 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-03-07T01:22:01.309Z,1741310521.309 [Startup:StartupSatComms:A](INFO): Timed out from 2025-03-07T01:21:01.1Z
2025-03-07T01:22:01.309Z,1741310521.309 [Startup:StartupSatComms:A] Stopped
2025-03-07T01:22:01.309Z,1741310521.309 [Startup:StartupSatComms:B] Running Loop=1
2025-03-07T01:22:01.704Z,1741310521.704 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-07T01:22:08.836Z,1741310528.836 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250307T010942/Courier0004.lzma
2025-03-07T01:22:09.836Z,1741310529.836 [DataOverHttps](INFO): Moved sent file to Logs/20250307T010942/Courier0004.lzma.bak
2025-03-07T01:22:09.836Z,1741310529.836 [DataOverHttps](INFO): SBD MOMSN=24137034
2025-03-07T01:22:25.490Z,1741310545.490 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20250307T011841/Courier0000.lzma
2025-03-07T01:22:26.492Z,1741310546.492 [DataOverHttps](INFO): Moved sent file to Logs/20250307T011841/Courier0000.lzma.bak
2025-03-07T01:22:26.492Z,1741310546.492 [DataOverHttps](INFO): SBD MOMSN=24137036
2025-03-07T01:22:41.151Z,1741310561.151 [DataOverHttps](INFO): Sending 684 bytes from file Logs/20250307T010942/Express0005.lzma
2025-03-07T01:22:42.152Z,1741310562.152 [DataOverHttps](INFO): Moved sent file to Logs/20250307T010942/Express0005.lzma.bak
2025-03-07T01:22:42.152Z,1741310562.152 [DataOverHttps](INFO): SBD MOMSN=24137041
2025-03-07T01:22:57.964Z,1741310577.964 [DataOverHttps](INFO): Sending 970 bytes from file Logs/20250307T011841/Express0001.lzma
2025-03-07T01:22:58.964Z,1741310578.964 [DataOverHttps](INFO): Moved sent file to Logs/20250307T011841/Express0001.lzma.bak
2025-03-07T01:22:58.964Z,1741310578.964 [DataOverHttps](INFO): SBD MOMSN=24137069
2025-03-07T01:23:00.283Z,1741310580.283 [Startup:StartupSatComms:B] Stopped
2025-03-07T01:23:00.283Z,1741310580.283 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-03-07T01:23:00.283Z,1741310580.283 [Startup:StartupSatComms] Stopped
2025-03-07T01:23:00.283Z,1741310580.283 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-03-07T01:23:00.284Z,1741310580.284 [Startup](INFO): Completed Startup
2025-03-07T01:23:00.284Z,1741310580.284 [MissionManager](INFO): Startup is completed.
2025-03-07T01:23:00.284Z,1741310580.284 [MissionManager](INFO): Uninitializing Mission Startup
2025-03-07T01:23:00.284Z,1741310580.284 [Startup] Stopped
2025-03-07T01:23:00.284Z,1741310580.284 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-03-07T01:23:00.284Z,1741310580.284 [Startup:A.GoToSurface] Stopped
2025-03-07T01:23:00.285Z,1741310580.285 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-07T01:23:00.675Z,1741310580.675 [MissionManager](IMPORTANT): Started mission Default
2025-03-07T01:23:00.675Z,1741310580.675 [Default] Running Loop=1
2025-03-07T01:23:00.675Z,1741310580.675 [Default](DEBUG): Aggregate::initialize Default
2025-03-07T01:23:00.675Z,1741310580.675 [Default:B.GoToSurface] Running Loop=1
2025-03-07T01:23:00.675Z,1741310580.675 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-07T01:23:00.675Z,1741310580.675 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-07T01:23:00.676Z,1741310580.676 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-07T01:23:00.676Z,1741310580.676 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-07T01:23:00.676Z,1741310580.676 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-07T01:23:00.677Z,1741310580.677 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-07T01:23:00.677Z,1741310580.677 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-07T01:23:00.677Z,1741310580.677 [Default:A.Wait] Running Loop=1
2025-03-07T01:23:00.677Z,1741310580.677 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-07T01:23:14.039Z,1741310594.039 [Default:A.Wait](INFO): Done Waiting.
2025-03-07T01:23:14.039Z,1741310594.039 [Default:A.Wait] Stopped
2025-03-07T01:23:14.039Z,1741310594.039 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-07T01:23:14.429Z,1741310594.429 [Default:CheckIn] Running Loop=1
2025-03-07T01:23:14.429Z,1741310594.429 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-07T01:23:14.429Z,1741310594.429 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-07T01:23:14.823Z,1741310594.823 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-07T01:23:59.304Z,1741310639.304 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-03-07T01:23:59.304Z,1741310639.304 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-03-07T01:23:59.304Z,1741310639.304 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-03-07T01:23:59.306Z,1741310639.306 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-03-07T01:23:59.819Z,1741310639.819 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
1
3
2
100
100
0
Waiting
for backseat to start up...
Disabling Optim recording after
Powering up Optim to try to tide over gap to handoff...
! echo 1 > /dev/loadC3
Optim power on. Spinning for
cycles.
1
! echo 0 > /dev/loadC3
Optim power off. Spinning again.
1
! echo 1 > /dev/loadC3
Optim power on. Handing off to mission.
! echo 1 > /dev/loadC3; sleep 1; echo 0 > /dev/loadC3; sleep 1; echo 1 > dev/loadC3
Hardcoded Optim command sent. Good luck.
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-03-07T01:23:59.827Z,1741310639.827 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-03-07T01:23:59.830Z,1741310639.830 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-03-07T01:23:59.833Z,1741310639.833 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-03-07T01:23:59.836Z,1741310639.836 [MissionManager](INFO): DefineArg lab_test_optim.UseMission = 1 bool
2025-03-07T01:23:59.839Z,1741310639.839 [MissionManager](INFO): DefineArg lab_test_optim.UseHardcode = 0 bool
2025-03-07T01:23:59.841Z,1741310639.841 [MissionManager](INFO): DefineArg lab_test_optim.InitialSampleTime = 1.000000 s
2025-03-07T01:23:59.845Z,1741310639.845 [MissionManager](INFO): DefineArg lab_test_optim.SleepCycles = 3.000000 count
2025-03-07T01:23:59.848Z,1741310639.848 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-03-07T01:23:59.852Z,1741310639.852 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-03-07T01:23:59.871Z,1741310639.871 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-03-07T01:23:59.879Z,1741310639.879 [MissionManager](INFO): DefineOutput lab_test_optim.CyclesWaited = 0.000000 count
2025-03-07T01:23:59.882Z,1741310639.882 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-03-07T01:23:59.889Z,1741310639.889 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-03-07T01:23:59.889Z,1741310639.889 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-03-07T01:23:59.889Z,1741310639.889 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-03-07T01:23:59.895Z,1741310639.895 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-03-07T01:23:59.937Z,1741310639.937 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-03-07T01:23:59.942Z,1741310639.942 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-03-07T01:23:59.962Z,1741310639.962 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-03-07T01:23:59.981Z,1741310639.981 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-03-07T01:24:00.003Z,1741310640.003 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Construct Wait.
2025-03-07T01:24:00.013Z,1741310640.013 [lab_test_optim:Startup:UseBackdoor:A.Execute](DEBUG): Construct Execute.
2025-03-07T01:24:00.052Z,1741310640.052 [lab_test_optim:Startup:UseBackdoor:D.Execute](DEBUG): Construct Execute.
2025-03-07T01:24:00.070Z,1741310640.070 [lab_test_optim:Startup:UseBackdoor:G.Execute](DEBUG): Construct Execute.
2025-03-07T01:24:00.096Z,1741310640.096 [lab_test_optim:Startup:UseHardcode:A.Execute](DEBUG): Construct Execute.
2025-03-07T01:24:00.173Z,1741310640.173 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-03-07T01:24:00.196Z,1741310640.196 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-03-07T01:24:00.208Z,1741310640.208 [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 lab_test_optim {
arguments {
MissionTimeout = 15 minute
"""
Backseat will stay on for this duration, independent of Optim state
"""
RecordTime = 1 minute
"""
How long to record after startup sequence (hopefully) turns on Optim camera
"""
BackseatWait = 30 second
"""
How long to wait for the backseat to power up before attempting to power the Optim
"""
UseMission = true
"""
If true, tries to go through the application and use components/behaviors for commands.
Set InitialSampleTime to change delays. If false, backdoors app. Use SleepCycles to change delays.
Optim must be on C3.
"""
UseHardcode = false
"""
If true, backdoors app with a powercycle and a hardcoded sleep 1. Try the two other modes first?
Optim must be on C3.
"""
InitialSampleTime = 1 second
"""
PowerOnly sample time for initial record. Will go back to continuous after startup.
"""
SleepCycles = 3 count
"""
How many vehicle computation cycles to wait before commanding the Optim off on initial record
"""
LightMode = 2 count
"""
Mode for Multiray lights. 0 is off, 1 is red, 2 is white
"""
BrightnessWhite = 100 none_int
"""
White Multiray LED brightness, 0-100
"""
BrightnessRed = 100 none_int
"""
Red Multiray LED brightness, 0-100
"""
}
output {
CyclesWaited = 0 count
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.samplePowerOnly
}
readData strategy="MinError" {
while ( LightsEnabled )
Sensor:MultiRay.lightModeLog
}
aggregate Startup {
run in sequence
syslog important "Waiting " + BackseatWait~s + " for backseat to start up..."
behavior Guidance:Wait {
run in sequence
set duration = BackseatWait
}
aggregate UseMission {
run in sequence
break if (
not UseMission
or UseHardcode
)
assign in parallel Sensor:PowerOnly.sampleTime1 = InitialSampleTime
assign in sequence RecordingEnabled = true
syslog important "Disabling Optim recording after " + InitialSampleTime~s
assign in sequence RecordingEnabled = false
behavior Guidance:Wait {
run in sequence
set duration = InitialSampleTime
}
assign in sequence RecordingEnabled = true
syslog important "Powering up Optim to try to tide over gap to handoff..."
}
aggregate UseBackdoor {
run in sequence
break if (
UseMission
or UseHardcode
)
behavior Guidance:Execute {
run in sequence
set command = "! echo 1 > /dev/loadC3"
}
syslog important "Optim power on. Spinning for " + SleepCycles~count + " cycles."
aggregate WaitForStop {
run in sequence repeat=SleepCycles
assign in sequence CyclesWaited = CyclesWaited + 1 count
}
behavior Guidance:Execute {
run in sequence
set command = "! echo 0 > /dev/loadC3"
}
syslog important "Optim power off. Spinning again."
aggregate WaitForStart {
run in sequence repeat=SleepCycles
assign in sequence CyclesWaited = CyclesWaited + 1 count
}
behavior Guidance:Execute {
run in sequence
set command = "! echo 1 > /dev/loadC3"
}
syslog important "Optim power on. Handing off to mission."
}
aggregate UseHardcode {
run in sequence
break if ( not UseHardcode )
behavior Guidance:Execute {
run in sequence
set command = "! echo 1 > /dev/loadC3; sleep 1; echo 0 > /dev/loadC3; sleep 1; echo 1 > dev/loadC3"
}
syslog important "Hardcoded Optim command sent. Good luck."
}
}
aggregate Run {
run in sequence
syslog important "Trying to run Optim and Multiray forreal"
assign in sequence RecordingEnabled = true
assign in sequence LightsEnabled = true
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode
aggregate setRed {
run in sequence
break if ( LightMode != 1 count )
assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
syslog info "Setting multiray red brightness to" + BrightnessRed~count
}
aggregate setWhite {
run in sequence
break if ( LightMode != 2 count )
assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
syslog info "Setting muliray white brightness to" + BrightnessWhite~count
}
syslog important "Recording for " + RecordTime~min
behavior Guidance:Wait {
run in sequence
set duration = RecordTime
}
}
behavior Guidance:Wait {
run in sequence
set duration = MissionTimeout
}
}
2025-03-07T01:24:00.215Z,1741310640.215 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-03-07T01:24:00.484Z,1741310640.484 [Default] Stopped
2025-03-07T01:24:00.485Z,1741310640.485 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-07T01:24:00.485Z,1741310640.485 [Default:B.GoToSurface] Stopped
2025-03-07T01:24:00.485Z,1741310640.485 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-07T01:24:00.485Z,1741310640.485 [Default:CheckIn] Stopped
2025-03-07T01:24:00.485Z,1741310640.485 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-07T01:24:00.485Z,1741310640.485 [Default:CheckIn:Read_GPS] Stopped
2025-03-07T01:24:00.485Z,1741310640.485 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-03-07T01:24:00.485Z,1741310640.485 [lab_test_optim] Running Loop=1
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim:BackseatDriver] Running Loop=1
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim:B] Running Loop=1
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim:C] Running Loop=1
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim:D] Running Loop=1
2025-03-07T01:24:00.486Z,1741310640.486 [lab_test_optim:Startup] Running Loop=1
2025-03-07T01:24:00.487Z,1741310640.487 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-03-07T01:24:00.487Z,1741310640.487 [lab_test_optim:Startup:A] Running Loop=1
2025-03-07T01:24:00.487Z,1741310640.487 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-03-07T01:24:00.488Z,1741310640.488 [lab_test_optim:Startup:A] Stopped
2025-03-07T01:24:00.488Z,1741310640.488 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-03-07T01:24:00.488Z,1741310640.488 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-03-07T01:24:00.488Z,1741310640.488 [lab_test_optim:D] Stopped
2025-03-07T01:24:00.488Z,1741310640.488 [lab_test_optim:C] Stopped
2025-03-07T01:24:00.488Z,1741310640.488 [lab_test_optim:B] Running Loop=1
2025-03-07T01:24:00.488Z,1741310640.488 [lab_test_optim:BackseatDriver] Running Loop=1
2025-03-07T01:24:00.489Z,1741310640.489 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-03-07T01:24:00.599Z,1741310640.599 [BackseatComponent](INFO): Powering up
2025-03-07T01:24:00.599Z,1741310640.599 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-07T01:24:31.185Z,1741310671.185 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-03-07T01:24:31.185Z,1741310671.185 [lab_test_optim:Startup:B.Wait] Stopped
2025-03-07T01:24:31.185Z,1741310671.185 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-03-07T01:24:31.186Z,1741310671.186 [lab_test_optim:Startup:UseMission] Running Loop=1
2025-03-07T01:24:31.186Z,1741310671.186 [lab_test_optim:Startup:UseMission](DEBUG): Aggregate::initialize lab_test_optim:Startup:UseMission
2025-03-07T01:24:31.186Z,1741310671.186 [lab_test_optim:Startup:UseMission:A] Running Loop=1
2025-03-07T01:24:31.186Z,1741310671.186 [lab_test_optim:Startup:UseMission:B] Running Loop=1
2025-03-07T01:24:31.609Z,1741310671.609 [lab_test_optim:Startup:UseMission:B] Stopped
2025-03-07T01:24:31.609Z,1741310671.609 [lab_test_optim:Startup:UseMission:C] Running Loop=1
2025-03-07T01:24:31.609Z,1741310671.609 [lab_test_optim:Startup:UseMission:A] Running Loop=1
2025-03-07T01:24:32.000Z,1741310672.000 [lab_test_optim:Startup:UseMission:C](IMPORTANT): Disabling Optim recording after 1.000000 s
2025-03-07T01:24:32.000Z,1741310672.000 [lab_test_optim:Startup:UseMission:C] Stopped
2025-03-07T01:24:32.001Z,1741310672.001 [lab_test_optim:Startup:UseMission:D] Running Loop=1
2025-03-07T01:24:32.001Z,1741310672.001 [lab_test_optim:C] Running Loop=1
2025-03-07T01:24:32.001Z,1741310672.001 [lab_test_optim:C] Running Loop=1
2025-03-07T01:24:32.002Z,1741310672.002 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.samplePowerOnly
2025-03-07T01:24:32.386Z,1741310672.386 [PowerOnly](INFO): Powering down loadControl
2025-03-07T01:24:32.401Z,1741310672.401 [lab_test_optim:Startup:UseMission:D] Stopped
2025-03-07T01:24:32.401Z,1741310672.401 [lab_test_optim:Startup:UseMission:E.Wait] Running Loop=1
2025-03-07T01:24:32.401Z,1741310672.401 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Initialize Wait Component.
2025-03-07T01:24:32.805Z,1741310672.805 [lab_test_optim:C] Stopped
2025-03-07T01:24:34.005Z,1741310674.005 [lab_test_optim:Startup:UseMission:E.Wait](INFO): Done Waiting.
2025-03-07T01:24:34.005Z,1741310674.005 [lab_test_optim:Startup:UseMission:E.Wait] Stopped
2025-03-07T01:24:34.005Z,1741310674.005 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Uninitialize Wait Component.
2025-03-07T01:24:34.006Z,1741310674.006 [lab_test_optim:Startup:UseMission:F] Running Loop=1
2025-03-07T01:24:34.408Z,1741310674.408 [lab_test_optim:Startup:UseMission:F] Stopped
2025-03-07T01:24:34.408Z,1741310674.408 [lab_test_optim:Startup:UseMission:G] Running Loop=1
2025-03-07T01:24:34.792Z,1741310674.792 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-07T01:24:34.826Z,1741310674.826 [lab_test_optim:Startup:UseMission:G](IMPORTANT): Powering up Optim to try to tide over gap to handoff...
2025-03-07T01:24:34.826Z,1741310674.826 [lab_test_optim:Startup:UseMission:G] Stopped
2025-03-07T01:24:34.827Z,1741310674.827 [lab_test_optim:Startup:UseMission](INFO): Completed lab_test_optim:Startup:UseMission
2025-03-07T01:24:34.827Z,1741310674.827 [lab_test_optim:Startup:UseMission] Stopped
2025-03-07T01:24:34.827Z,1741310674.827 [lab_test_optim:Startup:UseMission](DEBUG): Aggregate::uninitialize lab_test_optim:Startup:UseMission
2025-03-07T01:24:34.827Z,1741310674.827 [lab_test_optim:Startup:UseMission:A] Stopped
2025-03-07T01:24:34.827Z,1741310674.827 [lab_test_optim:Startup:UseBackdoor] Running Loop=1
2025-03-07T01:24:34.827Z,1741310674.827 [lab_test_optim:Startup:UseBackdoor](DEBUG): Aggregate::initialize lab_test_optim:Startup:UseBackdoor
2025-03-07T01:24:34.827Z,1741310674.827 [lab_test_optim:Startup:UseBackdoor:A.Execute] Running Loop=1
2025-03-07T01:24:34.828Z,1741310674.828 [lab_test_optim:C] Running Loop=1
2025-03-07T01:24:35.196Z,1741310675.196 [PowerOnly](INFO): Powering up loadControl
2025-03-07T01:24:35.241Z,1741310675.241 [lab_test_optim:Startup:UseBackdoor] Stopped
2025-03-07T01:24:35.241Z,1741310675.241 [lab_test_optim:Startup:UseBackdoor](DEBUG): Aggregate::uninitialize lab_test_optim:Startup:UseBackdoor
2025-03-07T01:24:35.241Z,1741310675.241 [lab_test_optim:Startup:UseBackdoor:A.Execute] Stopped
2025-03-07T01:24:35.241Z,1741310675.241 [lab_test_optim:Startup:UseHardcode] Running Loop=1
2025-03-07T01:24:35.241Z,1741310675.241 [lab_test_optim:Startup:UseHardcode](DEBUG): Aggregate::initialize lab_test_optim:Startup:UseHardcode
2025-03-07T01:24:35.241Z,1741310675.241 [lab_test_optim:Startup:UseHardcode:A.Execute] Running Loop=1
2025-03-07T01:24:35.628Z,1741310675.628 [lab_test_optim:Startup:UseHardcode] Stopped
2025-03-07T01:24:35.628Z,1741310675.628 [lab_test_optim:Startup:UseHardcode](DEBUG): Aggregate::uninitialize lab_test_optim:Startup:UseHardcode
2025-03-07T01:24:35.628Z,1741310675.628 [lab_test_optim:Startup:UseHardcode:A.Execute] Stopped
2025-03-07T01:24:35.628Z,1741310675.628 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-03-07T01:24:35.628Z,1741310675.628 [lab_test_optim:Startup] Stopped
2025-03-07T01:24:35.628Z,1741310675.628 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-03-07T01:24:35.629Z,1741310675.629 [lab_test_optim:Run] Running Loop=1
2025-03-07T01:24:35.629Z,1741310675.629 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-03-07T01:24:35.629Z,1741310675.629 [lab_test_optim:Run:A] Running Loop=1
2025-03-07T01:24:36.025Z,1741310676.025 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-03-07T01:24:36.025Z,1741310676.025 [lab_test_optim:Run:A] Stopped
2025-03-07T01:24:36.025Z,1741310676.025 [lab_test_optim:Run:B] Running Loop=1
2025-03-07T01:24:36.432Z,1741310676.432 [lab_test_optim:Run:B] Stopped
2025-03-07T01:24:36.432Z,1741310676.432 [lab_test_optim:Run:C] Running Loop=1
2025-03-07T01:24:36.853Z,1741310676.853 [lab_test_optim:Run:C] Stopped
2025-03-07T01:24:36.853Z,1741310676.853 [lab_test_optim:Run:D] Running Loop=1
2025-03-07T01:24:37.258Z,1741310677.258 [lab_test_optim:Run:D] Stopped
2025-03-07T01:24:37.258Z,1741310677.258 [lab_test_optim:Run:setRed] Running Loop=1
2025-03-07T01:24:37.262Z,1741310677.262 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-03-07T01:24:37.262Z,1741310677.262 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-03-07T01:24:37.262Z,1741310677.262 [lab_test_optim:D] Running Loop=1
2025-03-07T01:24:37.262Z,1741310677.262 [lab_test_optim:D] Running Loop=1
2025-03-07T01:24:37.263Z,1741310677.263 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-03-07T01:24:37.639Z,1741310677.639 [lab_test_optim:Run:setRed] Stopped
2025-03-07T01:24:37.639Z,1741310677.639 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-03-07T01:24:37.639Z,1741310677.639 [lab_test_optim:Run:setRed:A] Stopped
2025-03-07T01:24:37.639Z,1741310677.639 [lab_test_optim:Run:setWhite] Running Loop=1
2025-03-07T01:24:37.639Z,1741310677.639 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-03-07T01:24:37.640Z,1741310677.640 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-03-07T01:24:38.057Z,1741310678.057 [lab_test_optim:Run:setWhite:A] Stopped
2025-03-07T01:24:38.057Z,1741310678.057 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-03-07T01:24:38.469Z,1741310678.469 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-03-07T01:24:38.469Z,1741310678.469 [lab_test_optim:Run:setWhite:B] Stopped
2025-03-07T01:24:38.470Z,1741310678.470 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-03-07T01:24:38.470Z,1741310678.470 [lab_test_optim:Run:setWhite] Stopped
2025-03-07T01:24:38.470Z,1741310678.470 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-03-07T01:24:38.470Z,1741310678.470 [lab_test_optim:Run:G] Running Loop=1
2025-03-07T01:24:38.876Z,1741310678.876 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-03-07T01:24:38.876Z,1741310678.876 [lab_test_optim:Run:G] Stopped
2025-03-07T01:24:38.876Z,1741310678.876 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-03-07T01:24:38.876Z,1741310678.876 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-03-07T01:24:54.219Z,1741310694.219 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-03-07T01:24:54.219Z,1741310694.219 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-07T01:24:54.247Z,1741310694.247 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-07T01:24:54.665Z,1741310694.665 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-07T01:24:54.665Z,1741310694.665 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-03-07T01:24:58.959Z,1741310698.959 [BackseatComponent](IMPORTANT): ikshana: running backseat application.
2025-03-07T01:25:01.664Z,1741310701.664 [BackseatComponent](INFO): Created universal data reader for depth with code: 6
2025-03-07T01:25:01.665Z,1741310701.665 [BackseatComponent](INFO): Requesting data from depth (6). Requested size is: 1
2025-03-07T01:25:39.444Z,1741310739.444 [lab_test_optim:Run:H.Wait](INFO): Done Waiting.
2025-03-07T01:25:39.445Z,1741310739.445 [lab_test_optim:Run:H.Wait] Stopped
2025-03-07T01:25:39.445Z,1741310739.445 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-03-07T01:25:39.445Z,1741310739.445 [lab_test_optim:Run](INFO): Completed lab_test_optim:Run
2025-03-07T01:25:39.445Z,1741310739.445 [lab_test_optim:Run] Stopped
2025-03-07T01:25:39.445Z,1741310739.445 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-03-07T01:25:39.445Z,1741310739.445 [lab_test_optim:G.Wait] Running Loop=1
2025-03-07T01:25:39.445Z,1741310739.445 [lab_test_optim:G.Wait](DEBUG): Initialize Wait Component.
2025-03-07T01:26:16.604Z,1741310776.604 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-03-07T01:26:16.607Z,1741310776.607 [BPC1](INFO): Received data from all battery sticks.
2025-03-07T01:26:32.864Z,1741310792.864 [CommandExec](IMPORTANT): got command report mod
2025-03-07T01:26:32.864Z,1741310792.864 [CommandExec](FAULT): Incomplete syntax. Try: help report
2025-03-07T01:26:42.980Z,1741310802.980 [CommandExec](IMPORTANT): got command show variable poweronly
2025-03-07T01:26:43.000Z,1741310803.000 [CommandExec](IMPORTANT): PowerOnly.loadControl (none)
2025-03-07T01:26:43.001Z,1741310803.001 [CommandExec](IMPORTANT): PowerOnly.loadControl2 (none)
2025-03-07T01:26:43.001Z,1741310803.001 [CommandExec](IMPORTANT): PowerOnly.loadControl3 (none)
2025-03-07T01:26:43.076Z,1741310803.076 [CommandExec](IMPORTANT): PowerOnly.loadAtStartup (bool)
2025-03-07T01:26:43.076Z,1741310803.076 [CommandExec](IMPORTANT): PowerOnly.simulateHardware (bool)
2025-03-07T01:26:43.077Z,1741310803.077 [CommandExec](IMPORTANT): PowerOnly.sampleTime (second)
2025-03-07T01:26:43.077Z,1741310803.077 [CommandExec](IMPORTANT): PowerOnly.sampleTime1 (second)
2025-03-07T01:26:43.077Z,1741310803.077 [CommandExec](IMPORTANT): PowerOnly.sampleTime2 (second)
2025-03-07T01:26:43.078Z,1741310803.078 [CommandExec](IMPORTANT): PowerOnly.sampleTime3 (second)
2025-03-07T01:26:43.134Z,1741310803.134 [CommandExec](IMPORTANT): PowerOnly.enableBroadcast (bool)
2025-03-07T01:26:43.135Z,1741310803.135 [CommandExec](IMPORTANT): PowerOnly.samplePowerOnly (bool)
2025-03-07T01:26:43.135Z,1741310803.135 [CommandExec](IMPORTANT): PowerOnly.component_voltage_loadControl (volt)
2025-03-07T01:26:43.135Z,1741310803.135 [CommandExec](IMPORTANT): PowerOnly.component_avgVoltage_loadControl (volt)
2025-03-07T01:26:43.136Z,1741310803.136 [CommandExec](IMPORTANT): PowerOnly.component_current_loadControl (milliampere)
2025-03-07T01:26:43.136Z,1741310803.136 [CommandExec](IMPORTANT): PowerOnly.component_avgCurrent_loadControl (milliampere)
2025-03-07T01:26:43.136Z,1741310803.136 [CommandExec](IMPORTANT): PowerOnly.component_discreteIn_loadControl (bool)
2025-03-07T01:26:43.137Z,1741310803.137 [CommandExec](IMPORTANT): PowerOnly.sampleLoad1 (bool)
2025-03-07T01:26:53.466Z,1741310813.466 [CommandExec](IMPORTANT): got command report mod PowerOnly.component_avgCurrent_loadControl
2025-03-07T01:26:53.793Z,1741310813.793 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:26:59.092Z,1741310819.092 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 473.430023 mA
2025-03-07T01:27:01.530Z,1741310821.530 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 433.059998 mA
2025-03-07T01:27:03.939Z,1741310823.939 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:27:06.349Z,1741310826.349 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 433.059998 mA
2025-03-07T01:27:08.783Z,1741310828.783 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:27:11.213Z,1741310831.213 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 466.089996 mA
2025-03-07T01:27:13.665Z,1741310833.665 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:27:23.330Z,1741310843.330 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 444.070007 mA
2025-03-07T01:27:25.770Z,1741310845.770 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:27:33.027Z,1741310853.027 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 451.410004 mA
2025-03-07T01:27:35.441Z,1741310855.441 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 477.100006 mA
2025-03-07T01:27:37.872Z,1741310857.872 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:27:45.125Z,1741310865.125 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 444.070007 mA
2025-03-07T01:27:47.611Z,1741310867.611 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:27:54.829Z,1741310874.829 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 469.760010 mA
2025-03-07T01:27:55.215Z,1741310875.215 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-03-07T01:27:55.215Z,1741310875.215 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-07T01:27:55.226Z,1741310875.226 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-07T01:27:55.642Z,1741310875.642 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-07T01:27:55.642Z,1741310875.642 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-03-07T01:27:57.253Z,1741310877.253 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 477.100006 mA
2025-03-07T01:27:59.677Z,1741310879.677 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:28:02.101Z,1741310882.101 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 484.440002 mA
2025-03-07T01:28:04.542Z,1741310884.542 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:28:06.957Z,1741310886.957 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 447.740021 mA
2025-03-07T01:28:09.386Z,1741310889.386 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:28:11.801Z,1741310891.801 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 433.059998 mA
2025-03-07T01:28:14.233Z,1741310894.233 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:28:16.649Z,1741310896.649 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 469.760010 mA
2025-03-07T01:28:19.073Z,1741310899.073 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 477.100006 mA
2025-03-07T01:28:21.497Z,1741310901.497 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:28:28.765Z,1741310908.765 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 440.400024 mA
2025-03-07T01:28:31.181Z,1741310911.181 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:28:38.461Z,1741310918.461 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 455.080017 mA
2025-03-07T01:28:40.873Z,1741310920.873 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:28:45.733Z,1741310925.733 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 484.440002 mA
2025-03-07T01:28:48.165Z,1741310928.165 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 477.100006 mA
2025-03-07T01:28:50.573Z,1741310930.573 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 436.730011 mA
2025-03-07T01:28:53.005Z,1741310933.005 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 433.059998 mA
2025-03-07T01:28:57.857Z,1741310937.857 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:29:00.297Z,1741310940.297 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 469.760010 mA
2025-03-07T01:29:02.709Z,1741310942.709 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:29:07.549Z,1741310947.549 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 484.440002 mA
2025-03-07T01:29:09.965Z,1741310949.965 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 477.100006 mA
2025-03-07T01:29:12.405Z,1741310952.405 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 436.730011 mA
2025-03-07T01:29:14.821Z,1741310954.821 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:29:17.245Z,1741310957.245 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 433.059998 mA
2025-03-07T01:29:22.101Z,1741310962.101 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 473.430023 mA
2025-03-07T01:29:24.533Z,1741310964.533 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:29:32.944Z,1741310972.944 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-07T01:29:32.944Z,1741310972.944 [NAL9602] Data Fault, FailCount= 1
2025-03-07T01:29:32.944Z,1741310972.944 [NAL9602](ERROR): Data Fault
2025-03-07T01:29:33.011Z,1741310973.011 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-07T01:29:33.358Z,1741310973.358 [NAL9602](INFO): Powering down
2025-03-07T01:29:34.203Z,1741310974.203 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-07T01:29:34.203Z,1741310974.203 [NAL9602] No Fault, FailCount= 1
2025-03-07T01:29:34.206Z,1741310974.205 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 440.400024 mA
2025-03-07T01:29:36.641Z,1741310976.641 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 433.059998 mA
2025-03-07T01:29:41.485Z,1741310981.485 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:29:43.901Z,1741310983.901 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 458.750000 mA
2025-03-07T01:29:46.321Z,1741310986.321 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:29:56.038Z,1741310996.038 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 455.080017 mA
2025-03-07T01:29:58.453Z,1741310998.453 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:30:03.652Z,1741311003.652 [NAL9602](INFO): Powering up NAL9602
2025-03-07T01:30:05.739Z,1741311005.739 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 466.089996 mA
2025-03-07T01:30:08.197Z,1741311008.197 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:30:13.031Z,1741311013.031 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 484.440002 mA
2025-03-07T01:30:14.598Z,1741311014.598 [NAL9602](INFO): NAL9602 initialized
2025-03-07T01:30:17.889Z,1741311017.889 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 455.080017 mA
2025-03-07T01:30:20.297Z,1741311020.297 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 429.390015 mA
2025-03-07T01:30:22.731Z,1741311022.731 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 433.059998 mA
2025-03-07T01:30:27.579Z,1741311027.579 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 451.410004 mA
2025-03-07T01:30:29.997Z,1741311029.997 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 480.770020 mA
2025-03-07T01:30:35.791Z,1741311035.791 [CommandExec](IMPORTANT): got command quit
2025-03-07T01:30:36.794Z,1741311036.794 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2025-03-07T01:30:36.795Z,1741311036.795 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:36.795Z,1741311036.795 [CommandExec](INFO): Uninitializing the command executive.
2025-03-07T01:30:36.795Z,1741311036.795 [CommandExec](INFO): Uninitializing the command scheduler.
2025-03-07T01:30:36.795Z,1741311036.795 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:36.814Z,1741311036.814 [MissionManager](INFO): MissionManager is completed.
2025-03-07T01:30:36.814Z,1741311036.814 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-03-07T01:30:36.814Z,1741311036.814 [lab_test_optim] Stopped
2025-03-07T01:30:36.814Z,1741311036.814 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:BackseatDriver] Stopped
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:B] Stopped
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:C] Stopped
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:D] Stopped
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:G.Wait] Stopped
2025-03-07T01:30:36.815Z,1741311036.815 [lab_test_optim:G.Wait](DEBUG): Uninitialize Wait Component.
2025-03-07T01:30:36.910Z,1741311036.910 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2025-03-07T01:30:36.910Z,1741311036.910 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-03-07T01:30:36.910Z,1741311036.910 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:36.911Z,1741311036.911 [NavChartDb](INFO): Join timeout helper Thread ID is 1408
2025-03-07T01:30:37.219Z,1741311037.219 [MissionManager](IMPORTANT): Started mission Default
2025-03-07T01:30:37.220Z,1741311037.220 [Default] Running Loop=1
2025-03-07T01:30:37.221Z,1741311037.221 [Default](DEBUG): Aggregate::initialize Default
2025-03-07T01:30:37.221Z,1741311037.221 [Default:B.GoToSurface] Running Loop=1
2025-03-07T01:30:37.221Z,1741311037.221 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-07T01:30:37.222Z,1741311037.222 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-07T01:30:37.222Z,1741311037.222 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-07T01:30:37.223Z,1741311037.223 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-07T01:30:37.223Z,1741311037.223 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-07T01:30:37.223Z,1741311037.223 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-07T01:30:37.223Z,1741311037.223 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-07T01:30:37.224Z,1741311037.224 [Default:A.Wait] Running Loop=1
2025-03-07T01:30:37.224Z,1741311037.224 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-07T01:30:37.237Z,1741311037.237 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 484.440002 mA
2025-03-07T01:30:37.310Z,1741311037.310 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:37.311Z,1741311037.311 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:37.330Z,1741311037.330 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2025-03-07T01:30:37.330Z,1741311037.330 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:37.330Z,1741311037.330 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1409
2025-03-07T01:30:37.430Z,1741311037.430 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-07T01:30:37.431Z,1741311037.431 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-07T01:30:37.494Z,1741311037.494 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:37.495Z,1741311037.495 [WetLabsBB2FL](INFO): Powering down
2025-03-07T01:30:37.495Z,1741311037.495 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:37.510Z,1741311037.510 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2025-03-07T01:30:37.510Z,1741311037.510 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:37.511Z,1741311037.511 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1410
2025-03-07T01:30:38.150Z,1741311038.150 [CTD_Seabird](INFO): Powering down
2025-03-07T01:30:38.162Z,1741311038.162 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:38.162Z,1741311038.162 [CTD_Seabird](INFO): Powering down
2025-03-07T01:30:38.174Z,1741311038.174 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:38.174Z,1741311038.174 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-03-07T01:30:38.175Z,1741311038.175 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:38.175Z,1741311038.175 [Radio_Surface](INFO): Join timeout helper Thread ID is 1412
2025-03-07T01:30:38.198Z,1741311038.198 [Radio_Surface](INFO): Powering down
2025-03-07T01:30:38.199Z,1741311038.199 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:38.200Z,1741311038.200 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:38.214Z,1741311038.214 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-03-07T01:30:38.214Z,1741311038.214 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:38.215Z,1741311038.215 [Onboard](INFO): Join timeout helper Thread ID is 1413
2025-03-07T01:30:38.495Z,1741311038.495 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-03-07T01:30:38.766Z,1741311038.766 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:38.766Z,1741311038.766 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:38.783Z,1741311038.783 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-03-07T01:30:38.783Z,1741311038.783 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:38.783Z,1741311038.783 [DataOverHttps](INFO): Join timeout helper Thread ID is 1414
2025-03-07T01:30:39.498Z,1741311039.498 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:39.499Z,1741311039.499 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.511Z,1741311039.511 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2025-03-07T01:30:39.511Z,1741311039.511 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.511Z,1741311039.511 [BackseatComponent](INFO): Join timeout helper Thread ID is 1415
2025-03-07T01:30:39.670Z,1741311039.670 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:39.671Z,1741311039.671 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.675Z,1741311039.675 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2025-03-07T01:30:39.675Z,1741311039.675 [logger ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.675Z,1741311039.675 [logger](INFO): Join timeout helper Thread ID is 1416
2025-03-07T01:30:39.700Z,1741311039.700 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:39.701Z,1741311039.701 [logger ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.719Z,1741311039.719 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2025-03-07T01:30:39.719Z,1741311039.719 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.719Z,1741311039.719 [CommandLine](INFO): Join timeout helper Thread ID is 1417
2025-03-07T01:30:39.742Z,1741311039.742 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:39.743Z,1741311039.743 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.759Z,1741311039.759 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2025-03-07T01:30:39.759Z,1741311039.759 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.759Z,1741311039.759 [CommandExec](INFO): Join timeout helper Thread ID is 1418
2025-03-07T01:30:39.760Z,1741311039.760 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2025-03-07T01:30:39.761Z,1741311039.761 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.761Z,1741311039.761 [controlThread](INFO): Join timeout helper Thread ID is 1419
2025-03-07T01:30:39.817Z,1741311039.817 [Reporter](INFO): PowerOnly.component_avgCurrent_loadControl 466.089996 mA
2025-03-07T01:30:39.818Z,1741311039.818 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2025-03-07T01:30:39.818Z,1741311039.818 [controlThread](DEBUG): Uninitializing ControlThread
2025-03-07T01:30:39.818Z,1741311039.818 [AHRS_M2](INFO): Powering down
2025-03-07T01:30:39.891Z,1741311039.891 [MultiRay](INFO): Powering down.
2025-03-07T01:30:39.892Z,1741311039.892 [NAL9602](INFO): Powering down
2025-03-07T01:30:39.893Z,1741311039.893 [Waterlinked](INFO): Powering down
2025-03-07T01:30:39.895Z,1741311039.895 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2025-03-07T01:30:39.895Z,1741311039.895 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2025-03-07T01:30:39.896Z,1741311039.896 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2025-03-07T01:30:39.896Z,1741311039.896 [MissionManager](INFO): Uninitializing Mission Default
2025-03-07T01:30:39.896Z,1741311039.896 [Default] Stopped
2025-03-07T01:30:39.897Z,1741311039.897 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-07T01:30:39.897Z,1741311039.897 [Default:A.Wait] Stopped
2025-03-07T01:30:39.897Z,1741311039.897 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-07T01:30:39.897Z,1741311039.897 [Default:B.GoToSurface] Stopped
2025-03-07T01:30:39.897Z,1741311039.897 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-07T01:30:39.900Z,1741311039.900 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2025-03-07T01:30:39.900Z,1741311039.900 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2025-03-07T01:30:39.900Z,1741311039.900 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2025-03-07T01:30:39.900Z,1741311039.900 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2025-03-07T01:30:39.901Z,1741311039.901 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-03-07T01:30:39.901Z,1741311039.901 [BuoyancyServo](INFO): Powering down
2025-03-07T01:30:39.914Z,1741311039.914 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-03-07T01:30:39.914Z,1741311039.914 [ElevatorServo](INFO): Powering down
2025-03-07T01:30:39.915Z,1741311039.915 [MassServo](DEBUG): Uninitialize Mass Servo.
2025-03-07T01:30:39.915Z,1741311039.915 [MassServo](INFO): Powering down
2025-03-07T01:30:39.916Z,1741311039.916 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2025-03-07T01:30:39.916Z,1741311039.916 [RudderServo](INFO): Powering down
2025-03-07T01:30:39.917Z,1741311039.917 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-03-07T01:30:39.917Z,1741311039.917 [ThrusterHE](INFO): Powering down
2025-03-07T01:30:39.918Z,1741311039.918 [SBIT](DEBUG): Uninitialize SBIT Component.
2025-03-07T01:30:39.919Z,1741311039.919 [IBIT](DEBUG): Uninitialize IBIT Component.
2025-03-07T01:30:39.919Z,1741311039.919 [CBIT](DEBUG): Uninitialize CBIT Component.
2025-03-07T01:30:39.919Z,1741311039.919 [CBIT](DEBUG): Powering off loads.
2025-03-07T01:30:39.930Z,1741311039.930 [CBIT](DEBUG): Disabling WDT.
2025-03-07T01:30:39.942Z,1741311039.942 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-03-07T01:30:39.942Z,1741311039.942 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-03-07T01:30:39.943Z,1741311039.943 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.981Z,1741311039.981 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.985Z,1741311039.985 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:39.992Z,1741311039.992 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:40.039Z,1741311040.039 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:40.074Z,1741311040.074 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-03-07T01:30:40.074Z,1741311040.074 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-03-07T01:30:40.089Z,1741311040.089 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:40.094Z,1741311040.094 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:40.267Z,1741311040.267 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-03-07T01:30:40.316Z,1741311040.316 [logger ThreadHandler](INFO): Thread cancelled.