2025-04-07T16:45:34.486Z,1744044334.486 [Supervisor](DEBUG): Initializing supervisor.
2025-04-07T16:45:34.490Z,1744044334.490 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-04-07T16:45:34.491Z,1744044334.491 [SyncHandler](INFO): Protected caller Thread ID is 839
2025-04-07T16:45:34.491Z,1744044334.491 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-04-07T16:45:34.492Z,1744044334.492 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-04-07T16:45:34.492Z,1744044334.492 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840
2025-04-07T16:45:34.496Z,1744044334.496 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-04-07T16:45:34.517Z,1744044334.517 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-04-07T16:45:34.518Z,1744044334.518 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-04-07T16:45:34.519Z,1744044334.519 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841
2025-04-07T16:45:34.523Z,1744044334.523 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-04-07T16:45:34.524Z,1744044334.524 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-04-07T16:45:34.524Z,1744044334.524 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842
2025-04-07T16:45:34.527Z,1744044334.527 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-04-07T16:45:34.528Z,1744044334.528 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-04-07T16:45:34.528Z,1744044334.528 [logger ThreadHandler](INFO): Protected caller Thread ID is 843
2025-04-07T16:45:34.532Z,1744044334.532 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-04-07T16:45:34.532Z,1744044334.532 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-04-07T16:45:34.536Z,1744044334.536 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-04-07T16:45:34.758Z,1744044334.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-04-07T16:45:34.759Z,1744044334.759 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-04-07T16:45:34.876Z,1744044334.876 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-04-07T16:45:34.878Z,1744044334.878 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-04-07T16:45:34.983Z,1744044334.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-04-07T16:45:34.985Z,1744044334.985 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-04-07T16:45:35.484Z,1744044335.484 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-04-07T16:45:35.486Z,1744044335.486 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-04-07T16:45:35.847Z,1744044335.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-04-07T16:45:35.849Z,1744044335.849 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-04-07T16:45:36.226Z,1744044336.226 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-04-07T16:45:36.227Z,1744044336.227 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-04-07T16:45:36.427Z,1744044336.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-04-07T16:45:36.428Z,1744044336.428 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-04-07T16:45:36.518Z,1744044336.518 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-04-07T16:45:36.643Z,1744044336.643 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-04-07T16:45:37.719Z,1744044337.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-04-07T16:45:37.719Z,1744044337.719 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-04-07T16:45:38.024Z,1744044338.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-04-07T16:45:38.025Z,1744044338.025 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-04-07T16:45:38.592Z,1744044338.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-04-07T16:45:38.594Z,1744044338.594 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-04-07T16:45:38.849Z,1744044338.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-04-07T16:45:38.849Z,1744044338.849 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-04-07T16:45:39.104Z,1744044339.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-04-07T16:45:39.105Z,1744044339.105 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-04-07T16:45:39.255Z,1744044339.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-04-07T16:45:39.256Z,1744044339.256 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-04-07T16:45:40.142Z,1744044340.142 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-04-07T16:45:40.144Z,1744044340.144 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2025-04-07T16:45:40.148Z,1744044340.148 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2025-04-07T16:45:40.242Z,1744044340.242 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2025-04-07T16:45:40.384Z,1744044340.384 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2025-04-07T16:45:40.664Z,1744044340.664 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-04-07T16:45:40.664Z,1744044340.664 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2025-04-07T16:45:40.799Z,1744044340.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2025-04-07T16:45:40.905Z,1744044340.905 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2025-04-07T16:45:41.009Z,1744044341.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2025-04-07T16:45:41.128Z,1744044341.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2025-04-07T16:45:41.223Z,1744044341.223 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2025-04-07T16:45:41.319Z,1744044341.319 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2025-04-07T16:45:41.419Z,1744044341.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2025-04-07T16:45:41.597Z,1744044341.597 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-04-07T16:45:41.612Z,1744044341.612 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-04-07T16:45:41.686Z,1744044341.686 [DepthRateCalculator] Loaded
2025-04-07T16:45:41.686Z,1744044341.686 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-04-07T16:45:41.692Z,1744044341.692 [PitchRateCalculator] Loaded
2025-04-07T16:45:41.692Z,1744044341.692 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-04-07T16:45:41.702Z,1744044341.702 [SpeedCalculator] Loaded
2025-04-07T16:45:41.703Z,1744044341.703 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-04-07T16:45:41.708Z,1744044341.708 [YawRateCalculator] Loaded
2025-04-07T16:45:41.708Z,1744044341.708 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-04-07T16:45:41.730Z,1744044341.730 [ElevatorOffsetCalculator] Loaded
2025-04-07T16:45:41.730Z,1744044341.730 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-04-07T16:45:41.730Z,1744044341.730 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-04-07T16:45:41.732Z,1744044341.732 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-04-07T16:45:41.780Z,1744044341.780 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-04-07T16:45:41.781Z,1744044341.781 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-04-07T16:45:41.797Z,1744044341.797 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-04-07T16:45:41.798Z,1744044341.798 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-04-07T16:45:42.647Z,1744044342.647 [AHRS_M2] Loaded
2025-04-07T16:45:42.648Z,1744044342.648 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-04-07T16:45:42.901Z,1744044342.901 [BackseatComponent] Loaded
2025-04-07T16:45:42.902Z,1744044342.902 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-04-07T16:45:42.903Z,1744044342.903 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408754E0
2025-04-07T16:45:42.903Z,1744044342.903 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925
2025-04-07T16:45:42.906Z,1744044342.906 [LcmUniversalReporter] Loaded
2025-04-07T16:45:42.906Z,1744044342.906 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-04-07T16:45:43.866Z,1744044343.866 [BPC1] Loaded
2025-04-07T16:45:43.866Z,1744044343.866 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-04-07T16:45:43.962Z,1744044343.962 [DAT] Loaded
2025-04-07T16:45:43.962Z,1744044343.962 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-04-07T16:45:43.964Z,1744044343.964 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408A54E0
2025-04-07T16:45:43.964Z,1744044343.964 [DAT ThreadHandler](INFO): Protected caller Thread ID is 926
2025-04-07T16:45:44.110Z,1744044344.110 [DataOverHttps] Loaded
2025-04-07T16:45:44.110Z,1744044344.110 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-04-07T16:45:44.111Z,1744044344.111 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408D54E0
2025-04-07T16:45:44.111Z,1744044344.111 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 927
2025-04-07T16:45:44.134Z,1744044344.134 [Depth_Keller] Loaded
2025-04-07T16:45:44.134Z,1744044344.134 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-04-07T16:45:44.139Z,1744044344.139 [DropWeight] Loaded
2025-04-07T16:45:44.139Z,1744044344.139 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-04-07T16:45:44.161Z,1744044344.161 [MultiRay](INFO): Found secondary power supply at: /dev/loadC7
2025-04-07T16:45:44.161Z,1744044344.161 [MultiRay] Loaded
2025-04-07T16:45:44.161Z,1744044344.161 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2025-04-07T16:45:44.225Z,1744044344.225 [NAL9602] Loaded
2025-04-07T16:45:44.226Z,1744044344.226 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-04-07T16:45:44.255Z,1744044344.255 [Onboard] Loaded
2025-04-07T16:45:44.256Z,1744044344.256 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-04-07T16:45:44.257Z,1744044344.257 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409054E0
2025-04-07T16:45:44.257Z,1744044344.257 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 928
2025-04-07T16:45:44.263Z,1744044344.263 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2025-04-07T16:45:44.276Z,1744044344.276 [PowerOnly] Loaded
2025-04-07T16:45:44.277Z,1744044344.277 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-04-07T16:45:44.290Z,1744044344.290 [Power24vConverter] Loaded
2025-04-07T16:45:44.290Z,1744044344.290 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-04-07T16:45:44.308Z,1744044344.308 [Radio_Surface] Loaded
2025-04-07T16:45:44.308Z,1744044344.308 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-04-07T16:45:44.309Z,1744044344.309 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409354E0
2025-04-07T16:45:44.309Z,1744044344.309 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 929
2025-04-07T16:45:44.334Z,1744044344.334 [Waterlinked] Loaded
2025-04-07T16:45:44.334Z,1744044344.334 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2025-04-07T16:45:44.335Z,1744044344.335 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-04-07T16:45:44.335Z,1744044344.335 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-04-07T16:45:45.380Z,1744044345.380 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-04-07T16:45:45.448Z,1744044345.448 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-04-07T16:45:45.464Z,1744044345.464 [NavChart] Loaded
2025-04-07T16:45:45.465Z,1744044345.465 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-04-07T16:45:45.471Z,1744044345.471 [UniversalFixResidualReporter] Loaded
2025-04-07T16:45:45.471Z,1744044345.471 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-04-07T16:45:45.471Z,1744044345.471 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-04-07T16:45:45.472Z,1744044345.472 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-04-07T16:45:45.674Z,1744044345.674 [SBIT](DEBUG): Construct Startup Built In Test.
2025-04-07T16:45:45.688Z,1744044345.688 [SBIT] Loaded
2025-04-07T16:45:45.688Z,1744044345.688 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-04-07T16:45:45.691Z,1744044345.691 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-04-07T16:45:45.704Z,1744044345.704 [IBIT] Loaded
2025-04-07T16:45:45.705Z,1744044345.705 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-04-07T16:45:45.710Z,1744044345.710 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-04-07T16:45:45.791Z,1744044345.791 [CBIT] Loaded
2025-04-07T16:45:45.792Z,1744044345.792 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-04-07T16:45:45.824Z,1744044345.824 [GFScanner] Loaded
2025-04-07T16:45:45.824Z,1744044345.824 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-04-07T16:45:45.824Z,1744044345.824 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-04-07T16:45:45.825Z,1744044345.825 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-04-07T16:45:46.045Z,1744044346.045 [CTD_Seabird] Loaded
2025-04-07T16:45:46.045Z,1744044346.045 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-04-07T16:45:46.046Z,1744044346.046 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2025-04-07T16:45:46.047Z,1744044346.047 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 930
2025-04-07T16:45:46.069Z,1744044346.069 [PAR_Licor] Loaded
2025-04-07T16:45:46.070Z,1744044346.070 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-04-07T16:45:46.116Z,1744044346.116 [WetLabsBB2FL] Loaded
2025-04-07T16:45:46.116Z,1744044346.116 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-04-07T16:45:46.132Z,1744044346.132 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A774E0
2025-04-07T16:45:46.132Z,1744044346.132 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 931
2025-04-07T16:45:46.133Z,1744044346.133 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-04-07T16:45:46.134Z,1744044346.134 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-04-07T16:45:46.307Z,1744044346.307 [BuoyancyServo] Loaded
2025-04-07T16:45:46.307Z,1744044346.307 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-04-07T16:45:46.332Z,1744044346.332 [ElevatorServo] Loaded
2025-04-07T16:45:46.332Z,1744044346.332 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-04-07T16:45:46.355Z,1744044346.355 [MassServo] Loaded
2025-04-07T16:45:46.356Z,1744044346.356 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-04-07T16:45:46.378Z,1744044346.378 [RudderServo] Loaded
2025-04-07T16:45:46.378Z,1744044346.378 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-04-07T16:45:46.397Z,1744044346.397 [ThrusterHE] Loaded
2025-04-07T16:45:46.397Z,1744044346.397 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-04-07T16:45:46.397Z,1744044346.397 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-04-07T16:45:46.398Z,1744044346.398 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-04-07T16:45:46.471Z,1744044346.471 [VerticalControl](DEBUG): Construct VerticalControl.
2025-04-07T16:45:46.524Z,1744044346.524 [VerticalControl] Loaded
2025-04-07T16:45:46.524Z,1744044346.524 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-04-07T16:45:46.527Z,1744044346.527 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-04-07T16:45:46.573Z,1744044346.573 [HorizontalControl] Loaded
2025-04-07T16:45:46.573Z,1744044346.573 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-04-07T16:45:46.575Z,1744044346.575 [SpeedControl](DEBUG): Construct SpeedControl.
2025-04-07T16:45:46.577Z,1744044346.577 [SpeedControl] Loaded
2025-04-07T16:45:46.577Z,1744044346.577 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-04-07T16:45:46.580Z,1744044346.580 [LoopControl](DEBUG): Construct LoopControl.
2025-04-07T16:45:46.581Z,1744044346.581 [LoopControl] Loaded
2025-04-07T16:45:46.581Z,1744044346.581 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-04-07T16:45:46.582Z,1744044346.582 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-04-07T16:45:46.582Z,1744044346.582 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-04-07T16:45:46.750Z,1744044346.750 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-04-07T16:45:46.751Z,1744044346.751 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-04-07T16:45:46.973Z,1744044346.973 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-04-07T16:45:46.974Z,1744044346.974 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-04-07T16:45:47.393Z,1744044347.393 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-04-07T16:45:47.394Z,1744044347.394 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-04-07T16:45:47.482Z,1744044347.482 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-04-07T16:45:47.488Z,1744044347.488 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-04-07T16:45:47.491Z,1744044347.491 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-04-07T16:45:47.503Z,1744044347.503 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-04-07T16:45:47.504Z,1744044347.504 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0
2025-04-07T16:45:47.504Z,1744044347.504 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 932
2025-04-07T16:45:47.509Z,1744044347.509 [Supervisor](INFO): Main Thread ID is 830
2025-04-07T16:45:47.509Z,1744044347.509 [Supervisor](DEBUG): Running supervisor.
2025-04-07T16:45:47.510Z,1744044347.510 [CommandExec ThreadHandler](INFO): Handler Thread ID is 933
2025-04-07T16:45:47.510Z,1744044347.510 [CommandExec](INFO): Initializing the command executive.
2025-04-07T16:45:47.512Z,1744044347.512 [CommandLine ThreadHandler](INFO): Handler Thread ID is 934
2025-04-07T16:45:47.514Z,1744044347.514 [controlThread ThreadHandler](INFO): Handler Thread ID is 935
2025-04-07T16:45:47.514Z,1744044347.514 [controlThread](DEBUG): Initializing ControlThread
2025-04-07T16:45:47.515Z,1744044347.515 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-04-07T16:45:47.515Z,1744044347.515 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-04-07T16:45:47.516Z,1744044347.516 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-04-07T16:45:47.516Z,1744044347.516 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-04-07T16:45:47.516Z,1744044347.516 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-04-07T16:45:47.521Z,1744044347.521 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-04-07T16:45:47.521Z,1744044347.521 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-04-07T16:45:47.522Z,1744044347.522 [SBIT](INFO): Initialize SBIT Component.
2025-04-07T16:45:47.522Z,1744044347.522 [SBIT](IMPORTANT): git: 2025-04-02-2-g1635786d1
2025-04-07T16:45:47.522Z,1744044347.522 [SBIT](INFO): git hash: 1635786d188a1b3aba7073e6184020eb8609012e
2025-04-07T16:45:47.523Z,1744044347.523 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-04-07T16:45:47.524Z,1744044347.524 [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-04-07T16:45:47.525Z,1744044347.525 [SBIT](INFO): Beginning SBIT in 61.000000 seconds.
2025-04-07T16:45:47.525Z,1744044347.525 [IBIT](INFO): Initialize IBIT Component.
2025-04-07T16:45:47.526Z,1744044347.526 [CBIT](DEBUG): Initialize CBIT Component.
2025-04-07T16:45:47.527Z,1744044347.527 [logger ThreadHandler](INFO): Handler Thread ID is 936
2025-04-07T16:45:47.537Z,1744044347.537 [CBIT](DEBUG): Initialized mux pins.
2025-04-07T16:45:47.537Z,1744044347.537 [CBIT](DEBUG): Initializing the watchdog timer.
2025-04-07T16:45:47.545Z,1744044347.545 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937
2025-04-07T16:45:47.561Z,1744044347.561 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-04-07T16:45:47.561Z,1744044347.561 [CBIT](DEBUG): Initializing heartbeat.
2025-04-07T16:45:47.562Z,1744044347.562 [DAT ThreadHandler](INFO): Handler Thread ID is 938
2025-04-07T16:45:47.563Z,1744044347.563 [DAT](INFO): Powering up
2025-04-07T16:45:47.563Z,1744044347.563 [DAT](DEBUG): Initializing DAT.
2025-04-07T16:45:47.566Z,1744044347.566 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 940
2025-04-07T16:45:47.568Z,1744044347.568 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-04-07T16:45:47.589Z,1744044347.589 [Onboard ThreadHandler](INFO): Handler Thread ID is 941
2025-04-07T16:45:47.606Z,1744044347.606 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 942
2025-04-07T16:45:47.629Z,1744044347.629 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 943
2025-04-07T16:45:47.630Z,1744044347.630 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-04-07T16:45:47.633Z,1744044347.633 [CBIT](DEBUG): Deactivating emergency mode.
2025-04-07T16:45:47.634Z,1744044347.634 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 945
2025-04-07T16:45:47.637Z,1744044347.637 [WetLabsBB2FL](INFO): Powering up
2025-04-07T16:45:47.639Z,1744044347.639 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 947
2025-04-07T16:45:47.646Z,1744044347.646 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-04-07T16:45:47.646Z,1744044347.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-04-07T16:45:47.646Z,1744044347.646 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-04-07T16:45:47.647Z,1744044347.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-04-07T16:45:47.647Z,1744044347.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-04-07T16:45:47.647Z,1744044347.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-04-07T16:45:47.647Z,1744044347.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-04-07T16:45:47.647Z,1744044347.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-04-07T16:45:47.673Z,1744044347.673 [CBIT](DEBUG): Backplane powered.
2025-04-07T16:45:47.673Z,1744044347.673 [GFScanner](DEBUG): Initializing GFScanner
2025-04-07T16:45:47.673Z,1744044347.673 [GFScanner](DEBUG): Deactivating GF circuits.
2025-04-07T16:45:47.682Z,1744044347.682 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-04-07T16:45:47.684Z,1744044347.684 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-04-07T16:45:47.685Z,1744044347.685 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-04-07T16:45:47.685Z,1744044347.685 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-04-07T16:45:47.686Z,1744044347.686 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-04-07T16:45:47.687Z,1744044347.687 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-04-07T16:45:47.687Z,1744044347.687 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-04-07T16:45:47.691Z,1744044347.691 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-04-07T16:45:47.756Z,1744044347.756 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-04-07T16:45:47.760Z,1744044347.760 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-07T16:45:47.784Z,1744044347.784 [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-04-07T16:45:47.805Z,1744044347.805 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-04-07T16:45:47.805Z,1744044347.805 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-04-07T16:45:47.816Z,1744044347.816 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-04-07T16:45:48.013Z,1744044348.013 [Radio_Surface](INFO): Powering up
2025-04-07T16:45:48.019Z,1744044348.019 [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-04-07T16:45:48.034Z,1744044348.034 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-04-07T16:45:48.035Z,1744044348.035 [Default:A.Wait](DEBUG): Construct Wait.
2025-04-07T16:45:48.037Z,1744044348.037 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-07T16:45:48.057Z,1744044348.057 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-04-07T16:45:48.060Z,1744044348.060 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-04-07T16:45:48.082Z,1744044348.082 [Default:E.Execute](DEBUG): Construct Execute.
2025-04-07T16:45:48.085Z,1744044348.085 [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-04-07T16:45:48.098Z,1744044348.098 [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-04-07T16:45:48.113Z,1744044348.113 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-04-07T16:45:48.225Z,1744044348.225 [Depth_Keller](INFO): Initializing.
2025-04-07T16:45:48.226Z,1744044348.226 [MultiRay](INFO): Powering up MultiRay Lights
2025-04-07T16:45:48.227Z,1744044348.227 [MultiRay](INFO): Powering up secondary power supply.
2025-04-07T16:45:48.262Z,1744044348.262 [Power24vConverter](INFO): Powering up.
2025-04-07T16:45:48.282Z,1744044348.282 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-04-07T16:45:48.304Z,1744044348.304 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:45:48.313Z,1744044348.313 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-04-07T16:45:48.314Z,1744044348.314 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:45:48.321Z,1744044348.321 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-04-07T16:45:48.322Z,1744044348.322 [MassServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:45:48.329Z,1744044348.329 [MassServo](DEBUG): Initializing MassServo.
2025-04-07T16:45:48.330Z,1744044348.330 [RudderServo](DEBUG): Initializing EZServoServo.
2025-04-07T16:45:48.337Z,1744044348.337 [RudderServo](DEBUG): Initializing RudderServo.
2025-04-07T16:45:48.338Z,1744044348.338 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-04-07T16:45:48.345Z,1744044348.345 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-04-07T16:45:50.249Z,1744044350.249 [WetLabsBB2FL](INFO): Powering down
2025-04-07T16:45:54.038Z,1744044354.038 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-04-07T16:45:59.916Z,1744044359.916 [DAT](INFO): DAT read:
2025-04-07T16:45:59.917Z,1744044359.917 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-04-07T16:46:01.426Z,1744044361.426 [DAT](INFO): DAT read: MF Frequency Band
2025-04-07T16:46:01.427Z,1744044361.427 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-04-07T16:46:01.428Z,1744044361.428 [DAT](INFO): DAT read: Apr 4 2025 21:52:44
2025-04-07T16:46:02.434Z,1744044362.434 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-04-07T16:46:02.435Z,1744044362.435 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-04-07T16:46:02.436Z,1744044362.436 [DAT](INFO): commRate: 800
2025-04-07T16:46:04.501Z,1744044364.501 [DAT](INFO): entering command mode
2025-04-07T16:46:04.701Z,1744044364.701 [DAT](INFO): DAT read:
2025-04-07T16:46:04.702Z,1744044364.702 [DAT](INFO): DAT read: user:1>
2025-04-07T16:46:04.702Z,1744044364.702 [DAT](INFO): setting verbose to 3
2025-04-07T16:46:04.954Z,1744044364.954 [DAT](INFO): DAT read: user:1>
2025-04-07T16:46:04.955Z,1744044364.955 [DAT](INFO): DAT read: Verbose | 3
2025-04-07T16:46:04.955Z,1744044364.955 [DAT](INFO): set verbose to 3
2025-04-07T16:46:04.955Z,1744044364.955 [DAT](INFO): setting DatVerbose to 27440
2025-04-07T16:46:05.206Z,1744044365.206 [DAT](INFO): DAT read: user:2>
2025-04-07T16:46:05.207Z,1744044365.207 [DAT](INFO): DAT read: DatVerbose | 27440
2025-04-07T16:46:05.207Z,1744044365.207 [DAT](INFO): set DatVerbose to 27440
2025-04-07T16:46:05.207Z,1744044365.207 [DAT](INFO): setting transmit power to 8
2025-04-07T16:46:05.458Z,1744044365.458 [DAT](INFO): DAT read: user:3>
2025-04-07T16:46:05.459Z,1744044365.459 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-04-07T16:46:05.459Z,1744044365.459 [DAT](INFO): set transmit power to 8
2025-04-07T16:46:05.459Z,1744044365.459 [DAT](INFO): setting local address to 9
2025-04-07T16:46:05.710Z,1744044365.710 [DAT](INFO): DAT read: user:4>
2025-04-07T16:46:05.711Z,1744044365.711 [DAT](INFO): DAT read: LocalAddr | 9
2025-04-07T16:46:05.711Z,1744044365.711 [DAT](INFO): set local address to 9
2025-04-07T16:46:05.712Z,1744044365.712 [DAT](INFO): Setting time to: 16:46:5 And date to:4/7/2025
2025-04-07T16:46:05.962Z,1744044365.962 [DAT](INFO): DAT read: user:5>
2025-04-07T16:46:05.963Z,1744044365.963 [DAT](INFO): DAT read: Mon Apr 7, 2025 16:46:05
2025-04-07T16:46:05.963Z,1744044365.963 [DAT](INFO): Local DAT time set to Mon Apr 7, 2025 16:46:05
2025-04-07T16:46:14.443Z,1744044374.443 [NAL9602](INFO): Powering up NAL9602
2025-04-07T16:46:25.351Z,1744044385.351 [NAL9602](INFO): NAL9602 initialized
2025-04-07T16:46:25.445Z,1744044385.445 [Waterlinked](INFO): Powering down
2025-04-07T16:46:32.898Z,1744044392.898 [CommandExec](IMPORTANT): got command burn on
2025-04-07T16:46:32.898Z,1744044392.898 [CommandExec](IMPORTANT): Activating dropweight wire
2025-04-07T16:46:49.250Z,1744044409.250 [SBIT](IMPORTANT): Beginning Startup BIT
2025-04-07T16:46:49.254Z,1744044409.254 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-07T16:46:49.958Z,1744044409.958 [CommandExec](IMPORTANT): got command burn off
2025-04-07T16:46:49.958Z,1744044409.958 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-04-07T16:46:53.838Z,1744044413.838 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.000455
CHAN A1 (24V): 0.000151
CHAN A2 (12V): -0.005722
CHAN A3 (5V): -0.002190
CHAN B0 (3.3V): -0.000163
CHAN B1 (3.15aV): -0.001647
CHAN B2 (3.15bV): -0.001894
CHAN B3 (GND): 0.000188
OPEN: 0.004679
Full Scale: +/- 1 mA
2025-04-07T16:47:17.180Z,1744044437.180 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-04-07T16:47:43.004Z,1744044463.004 [SBIT](IMPORTANT): SBIT PASSED
2025-04-07T16:47:43.004Z,1744044463.004 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-04-07T16:47:43.005Z,1744044463.005 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;
2025-04-07T16:47:43.005Z,1744044463.005 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-04-07T16:47:43.005Z,1744044463.005 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;
2025-04-07T16:47:43.005Z,1744044463.005 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;
2025-04-07T16:47:43.005Z,1744044463.005 [SBIT](IMPORTANT): MultiRay.brightnessWhite=100 none;
2025-04-07T16:47:43.006Z,1744044463.006 [SBIT](IMPORTANT): MultiRay.loadAtStartup=1 bool;
2025-04-07T16:47:43.006Z,1744044463.006 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool;
2025-04-07T16:47:43.006Z,1744044463.006 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;
2025-04-07T16:47:43.006Z,1744044463.006 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=241.314617 cubic_centimeter;
2025-04-07T16:47:43.006Z,1744044463.006 [SBIT](IMPORTANT): VerticalControl.massDefault=10.352381 millimeter;
2025-04-07T16:47:43.413Z,1744044463.413 [MissionManager](IMPORTANT): Started mission Startup
2025-04-07T16:47:43.414Z,1744044463.414 [Startup] Running Loop=1
2025-04-07T16:47:43.414Z,1744044463.414 [Startup](DEBUG): Aggregate::initialize Startup
2025-04-07T16:47:43.414Z,1744044463.414 [Startup:A.GoToSurface] Running Loop=1
2025-04-07T16:47:43.414Z,1744044463.414 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T16:47:43.414Z,1744044463.414 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T16:47:43.415Z,1744044463.415 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T16:47:43.415Z,1744044463.415 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T16:47:43.415Z,1744044463.415 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T16:47:43.416Z,1744044463.416 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T16:47:43.416Z,1744044463.416 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T16:47:43.418Z,1744044463.418 [Startup:StartupSatComms] Running Loop=1
2025-04-07T16:47:43.418Z,1744044463.418 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-04-07T16:47:43.418Z,1744044463.418 [Startup:StartupSatComms:A] Running Loop=1
2025-04-07T16:47:43.608Z,1744044463.608 [CommandExec](IMPORTANT): got command strobe off
2025-04-07T16:47:43.608Z,1744044463.608 [CommandExec](IMPORTANT): Deactivating strobe
2025-04-07T16:47:43.808Z,1744044463.808 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-04-07T16:47:47.574Z,1744044467.574 [CommandExec](IMPORTANT): got command burn on
2025-04-07T16:47:47.574Z,1744044467.574 [CommandExec](IMPORTANT): Activating dropweight wire
2025-04-07T16:48:03.518Z,1744044483.518 [CommandExec](IMPORTANT): got command burn off
2025-04-07T16:48:03.518Z,1744044483.518 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-04-07T16:48:14.159Z,1744044494.159 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-04-07T16:48:20.222Z,1744044500.222 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-04-07T16:48:26.532Z,1744044506.532 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005147
2025-04-07T16:48:41.841Z,1744044521.841 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-04-07T16:48:43.467Z,1744044523.467 [Startup:StartupSatComms:A](INFO): Timed out from 2025-04-07T16:47:43.4Z
2025-04-07T16:48:43.467Z,1744044523.467 [Startup:StartupSatComms:A] Stopped
2025-04-07T16:48:43.467Z,1744044523.467 [Startup:StartupSatComms:B] Running Loop=1
2025-04-07T16:48:43.874Z,1744044523.874 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-07T16:48:47.913Z,1744044527.913 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-04-07T16:48:47.913Z,1744044527.913 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T16:48:47.932Z,1744044527.932 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T16:48:48.335Z,1744044528.335 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T16:48:48.335Z,1744044528.335 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-04-07T16:48:50.737Z,1744044530.737 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T164534/Courier0000.lzma
2025-04-07T16:48:51.740Z,1744044531.740 [DataOverHttps](INFO): Moved sent file to Logs/20250407T164534/Courier0000.lzma.bak
2025-04-07T16:48:51.740Z,1744044531.740 [DataOverHttps](INFO): SBD MOMSN=24561040
2025-04-07T16:49:07.603Z,1744044547.603 [DataOverHttps](INFO): Sending 989 bytes from file Logs/20250407T164534/Express0001.lzma
2025-04-07T16:49:08.603Z,1744044548.603 [DataOverHttps](INFO): Moved sent file to Logs/20250407T164534/Express0001.lzma.bak
2025-04-07T16:49:08.603Z,1744044548.603 [DataOverHttps](INFO): SBD MOMSN=24561043
2025-04-07T16:49:09.724Z,1744044549.724 [Startup:StartupSatComms:B] Stopped
2025-04-07T16:49:09.724Z,1744044549.724 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-04-07T16:49:09.724Z,1744044549.724 [Startup:StartupSatComms] Stopped
2025-04-07T16:49:09.724Z,1744044549.724 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-04-07T16:49:09.725Z,1744044549.725 [Startup](INFO): Completed Startup
2025-04-07T16:49:09.725Z,1744044549.725 [MissionManager](INFO): Startup is completed.
2025-04-07T16:49:09.725Z,1744044549.725 [MissionManager](INFO): Uninitializing Mission Startup
2025-04-07T16:49:09.725Z,1744044549.725 [Startup] Stopped
2025-04-07T16:49:09.725Z,1744044549.725 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-04-07T16:49:09.726Z,1744044549.726 [Startup:A.GoToSurface] Stopped
2025-04-07T16:49:09.726Z,1744044549.726 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T16:49:10.130Z,1744044550.130 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T16:49:10.131Z,1744044550.131 [Default] Running Loop=1
2025-04-07T16:49:10.131Z,1744044550.131 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T16:49:10.131Z,1744044550.131 [Default:B.GoToSurface] Running Loop=1
2025-04-07T16:49:10.131Z,1744044550.131 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T16:49:10.131Z,1744044550.131 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T16:49:10.131Z,1744044550.131 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T16:49:10.132Z,1744044550.132 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T16:49:10.132Z,1744044550.132 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T16:49:10.132Z,1744044550.132 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T16:49:10.132Z,1744044550.132 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T16:49:10.133Z,1744044550.133 [Default:A.Wait] Running Loop=1
2025-04-07T16:49:10.133Z,1744044550.133 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:49:23.479Z,1744044563.479 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T16:49:23.479Z,1744044563.479 [Default:A.Wait] Stopped
2025-04-07T16:49:23.479Z,1744044563.479 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:49:23.868Z,1744044563.868 [Default:CheckIn] Running Loop=1
2025-04-07T16:49:23.868Z,1744044563.868 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:49:23.869Z,1744044563.869 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:49:24.267Z,1744044564.267 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-04-07T16:49:27.134Z,1744044567.134 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-04-07T16:50:06.170Z,1744044606.170 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:50:06.171Z,1744044606.171 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:50:06.171Z,1744044606.171 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:50:06.175Z,1744044606.175 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:50:06.482Z,1744044606.482 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T16:50:06.487Z,1744044606.487 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T16:50:06.510Z,1744044606.510 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T16:50:06.519Z,1744044606.519 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T16:50:06.523Z,1744044606.523 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T16:50:06.538Z,1744044606.538 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T16:50:06.545Z,1744044606.545 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T16:50:06.548Z,1744044606.548 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T16:50:06.552Z,1744044606.552 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T16:50:06.553Z,1744044606.553 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T16:50:06.562Z,1744044606.562 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T16:50:06.563Z,1744044606.563 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T16:50:06.610Z,1744044606.610 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T16:50:06.615Z,1744044606.615 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T16:50:06.626Z,1744044606.626 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T16:50:06.644Z,1744044606.644 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T16:50:06.766Z,1744044606.766 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T16:50:06.768Z,1744044606.768 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T16:50:06.786Z,1744044606.786 [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
"""
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 {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
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 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-04-07T16:50:06.788Z,1744044606.788 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:50:07.091Z,1744044607.091 [Default] Stopped
2025-04-07T16:50:07.091Z,1744044607.091 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T16:50:07.091Z,1744044607.091 [Default:B.GoToSurface] Stopped
2025-04-07T16:50:07.091Z,1744044607.091 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T16:50:07.091Z,1744044607.091 [Default:CheckIn] Stopped
2025-04-07T16:50:07.091Z,1744044607.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:50:07.091Z,1744044607.091 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:50:07.091Z,1744044607.091 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim] Running Loop=1
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:B] Running Loop=1
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:C] Running Loop=1
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:D] Running Loop=1
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:Startup] Running Loop=1
2025-04-07T16:50:07.092Z,1744044607.092 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T16:50:07.093Z,1744044607.093 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:Startup:A] Stopped
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:D] Stopped
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:C] Stopped
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:B] Running Loop=1
2025-04-07T16:50:07.094Z,1744044607.094 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T16:50:07.095Z,1744044607.095 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T16:50:07.261Z,1744044607.261 [BackseatComponent](INFO): Powering up
2025-04-07T16:50:07.262Z,1744044607.262 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T16:50:27.719Z,1744044627.719 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-04-07T16:50:37.791Z,1744044637.791 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T16:50:37.791Z,1744044637.791 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T16:50:37.791Z,1744044637.791 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:50:37.791Z,1744044637.791 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T16:50:37.791Z,1744044637.791 [lab_test_optim:Startup] Stopped
2025-04-07T16:50:37.791Z,1744044637.791 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T16:50:37.792Z,1744044637.792 [lab_test_optim:Run] Running Loop=1
2025-04-07T16:50:37.792Z,1744044637.792 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T16:50:37.792Z,1744044637.792 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T16:50:38.200Z,1744044638.200 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T16:50:38.200Z,1744044638.200 [lab_test_optim:Run:A] Stopped
2025-04-07T16:50:38.201Z,1744044638.201 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T16:50:38.596Z,1744044638.596 [lab_test_optim:Run:B] Stopped
2025-04-07T16:50:38.596Z,1744044638.596 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T16:50:39.000Z,1744044639.000 [lab_test_optim:Run:C] Stopped
2025-04-07T16:50:39.001Z,1744044639.001 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T16:50:39.001Z,1744044639.001 [lab_test_optim:C] Running Loop=1
2025-04-07T16:50:39.001Z,1744044639.001 [lab_test_optim:C] Running Loop=1
2025-04-07T16:50:39.002Z,1744044639.002 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T16:50:39.396Z,1744044639.396 [PowerOnly](INFO): Powering up loadControl
2025-04-07T16:50:39.430Z,1744044639.430 [lab_test_optim:Run:D] Stopped
2025-04-07T16:50:39.431Z,1744044639.431 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T16:50:39.431Z,1744044639.431 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T16:50:39.431Z,1744044639.431 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T16:50:39.431Z,1744044639.431 [lab_test_optim:D] Running Loop=1
2025-04-07T16:50:39.431Z,1744044639.431 [lab_test_optim:D] Running Loop=1
2025-04-07T16:50:39.432Z,1744044639.432 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T16:50:39.815Z,1744044639.815 [lab_test_optim:Run:setRed] Stopped
2025-04-07T16:50:39.815Z,1744044639.815 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T16:50:39.815Z,1744044639.815 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T16:50:39.815Z,1744044639.815 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T16:50:39.816Z,1744044639.816 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T16:50:39.816Z,1744044639.816 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T16:50:40.236Z,1744044640.236 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T16:50:40.236Z,1744044640.236 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T16:50:40.676Z,1744044640.676 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T16:50:40.676Z,1744044640.676 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T16:50:40.676Z,1744044640.676 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T16:50:40.676Z,1744044640.676 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T16:50:40.676Z,1744044640.676 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T16:50:40.676Z,1744044640.676 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T16:50:41.044Z,1744044641.044 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T16:50:41.044Z,1744044641.044 [lab_test_optim:Run:G] Stopped
2025-04-07T16:50:41.044Z,1744044641.044 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T16:50:41.044Z,1744044641.044 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:50:41.926Z,1744044641.926 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-04-07T16:50:41.930Z,1744044641.930 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T16:51:05.231Z,1744044665.231 [BackseatComponent](IMPORTANT): ikshana: running backseat application.
2025-04-07T16:51:07.935Z,1744044667.935 [BackseatComponent](INFO): Created universal data reader for depth with code: 6
2025-04-07T16:51:07.936Z,1744044667.936 [BackseatComponent](INFO): Requesting data from depth (6). Requested size is: 1
2025-04-07T16:51:28.295Z,1744044688.295 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:Run:H.Wait](INFO): Done Waiting.
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:Run](INFO): Completed lab_test_optim:Run
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:Run] Stopped
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:G.Wait] Running Loop=1
2025-04-07T16:51:41.620Z,1744044701.620 [lab_test_optim:G.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:51:48.895Z,1744044708.895 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-04-07T16:51:48.895Z,1744044708.895 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T16:51:48.909Z,1744044708.909 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T16:51:49.313Z,1744044709.313 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T16:51:49.313Z,1744044709.313 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-04-07T16:51:51.350Z,1744044711.350 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-04-07T16:52:21.034Z,1744044741.034 [CommandExec](IMPORTANT): got command stop
2025-04-07T16:52:21.034Z,1744044741.034 [CommandExec](IMPORTANT): Scheduling is paused
2025-04-07T16:52:21.034Z,1744044741.034 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T16:52:21.213Z,1744044741.213 [MissionManager](INFO): MissionManager is completed.
2025-04-07T16:52:21.213Z,1744044741.213 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T16:52:21.213Z,1744044741.213 [lab_test_optim] Stopped
2025-04-07T16:52:21.213Z,1744044741.213 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T16:52:21.213Z,1744044741.213 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T16:52:21.214Z,1744044741.214 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T16:52:21.214Z,1744044741.214 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T16:52:21.214Z,1744044741.214 [lab_test_optim:B] Stopped
2025-04-07T16:52:21.214Z,1744044741.214 [lab_test_optim:C] Stopped
2025-04-07T16:52:21.214Z,1744044741.214 [lab_test_optim:D] Stopped
2025-04-07T16:52:21.214Z,1744044741.214 [lab_test_optim:G.Wait] Stopped
2025-04-07T16:52:21.214Z,1744044741.214 [lab_test_optim:G.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:52:21.284Z,1744044741.284 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T16:52:21.284Z,1744044741.284 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T16:52:21.620Z,1744044741.620 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T16:52:21.620Z,1744044741.620 [Default] Running Loop=1
2025-04-07T16:52:21.621Z,1744044741.621 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T16:52:21.621Z,1744044741.621 [Default:B.GoToSurface] Running Loop=1
2025-04-07T16:52:21.621Z,1744044741.621 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T16:52:21.621Z,1744044741.621 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T16:52:21.621Z,1744044741.621 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T16:52:21.622Z,1744044741.622 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T16:52:21.622Z,1744044741.622 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T16:52:21.622Z,1744044741.622 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T16:52:21.623Z,1744044741.623 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T16:52:21.623Z,1744044741.623 [Default:A.Wait] Running Loop=1
2025-04-07T16:52:21.623Z,1744044741.623 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:52:34.962Z,1744044754.962 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T16:52:34.963Z,1744044754.963 [Default:A.Wait] Stopped
2025-04-07T16:52:34.963Z,1744044754.963 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:52:35.356Z,1744044755.356 [Default:CheckIn] Running Loop=1
2025-04-07T16:52:35.356Z,1744044755.356 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T16:52:35.356Z,1744044755.356 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T16:52:39.461Z,1744044759.461 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T16:52:39.462Z,1744044759.462 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T16:52:39.462Z,1744044759.462 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T16:53:25.039Z,1744044805.039 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-04-07T16:53:25.042Z,1744044805.042 [BPC1](INFO): Received data from all battery sticks.
2025-04-07T16:53:51.709Z,1744044831.709 [PowerOnly](INFO): Powering down loadControl
2025-04-07T16:54:21.819Z,1744044861.819 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:54:21.820Z,1744044861.820 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:54:21.820Z,1744044861.820 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:54:21.822Z,1744044861.822 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:54:22.144Z,1744044862.144 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T16:54:22.149Z,1744044862.149 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T16:54:22.151Z,1744044862.151 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T16:54:22.153Z,1744044862.153 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T16:54:22.155Z,1744044862.155 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T16:54:22.158Z,1744044862.158 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T16:54:22.160Z,1744044862.160 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T16:54:22.195Z,1744044862.195 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T16:54:22.197Z,1744044862.197 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T16:54:22.198Z,1744044862.198 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T16:54:22.198Z,1744044862.198 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T16:54:22.199Z,1744044862.199 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T16:54:22.270Z,1744044862.270 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T16:54:22.275Z,1744044862.275 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T16:54:22.277Z,1744044862.277 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T16:54:22.298Z,1744044862.298 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T16:54:22.313Z,1744044862.313 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T16:54:22.314Z,1744044862.314 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T16:54:22.320Z,1744044862.320 [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
"""
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 {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
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 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-04-07T16:54:22.322Z,1744044862.322 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T16:54:22.459Z,1744044862.459 [Default] Stopped
2025-04-07T16:54:22.459Z,1744044862.459 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T16:54:22.459Z,1744044862.459 [Default:B.GoToSurface] Stopped
2025-04-07T16:54:22.459Z,1744044862.459 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T16:54:22.459Z,1744044862.459 [Default:CheckIn] Stopped
2025-04-07T16:54:22.459Z,1744044862.459 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T16:54:22.460Z,1744044862.460 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T16:54:22.460Z,1744044862.460 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T16:54:22.460Z,1744044862.460 [lab_test_optim] Running Loop=1
2025-04-07T16:54:22.460Z,1744044862.460 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T16:54:22.460Z,1744044862.460 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T16:54:22.460Z,1744044862.460 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T16:54:22.460Z,1744044862.460 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T16:54:22.460Z,1744044862.460 [lab_test_optim:B] Running Loop=1
2025-04-07T16:54:22.460Z,1744044862.460 [lab_test_optim:C] Running Loop=1
2025-04-07T16:54:22.461Z,1744044862.461 [lab_test_optim:D] Running Loop=1
2025-04-07T16:54:22.461Z,1744044862.461 [lab_test_optim:Startup] Running Loop=1
2025-04-07T16:54:22.461Z,1744044862.461 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T16:54:22.461Z,1744044862.461 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T16:54:22.462Z,1744044862.462 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T16:54:22.462Z,1744044862.462 [lab_test_optim:Startup:A] Stopped
2025-04-07T16:54:22.462Z,1744044862.462 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T16:54:22.462Z,1744044862.462 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:54:22.462Z,1744044862.462 [lab_test_optim:D] Stopped
2025-04-07T16:54:22.462Z,1744044862.462 [lab_test_optim:C] Stopped
2025-04-07T16:54:22.462Z,1744044862.462 [lab_test_optim:B] Running Loop=1
2025-04-07T16:54:22.463Z,1744044862.463 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T16:54:22.463Z,1744044862.463 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T16:54:22.573Z,1744044862.573 [BackseatComponent](INFO): Powering up
2025-04-07T16:54:22.574Z,1744044862.574 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T16:54:49.907Z,1744044889.907 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-04-07T16:54:49.907Z,1744044889.907 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T16:54:49.922Z,1744044889.922 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T16:54:50.305Z,1744044890.305 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T16:54:50.305Z,1744044890.305 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Startup] Stopped
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Run] Running Loop=1
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T16:54:53.135Z,1744044893.135 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T16:54:53.528Z,1744044893.528 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T16:54:53.528Z,1744044893.528 [lab_test_optim:Run:A] Stopped
2025-04-07T16:54:53.528Z,1744044893.528 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T16:54:53.935Z,1744044893.935 [lab_test_optim:Run:B] Stopped
2025-04-07T16:54:53.935Z,1744044893.935 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T16:54:54.356Z,1744044894.356 [lab_test_optim:Run:C] Stopped
2025-04-07T16:54:54.356Z,1744044894.356 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T16:54:54.356Z,1744044894.356 [lab_test_optim:C] Running Loop=1
2025-04-07T16:54:54.356Z,1744044894.356 [lab_test_optim:C] Running Loop=1
2025-04-07T16:54:54.356Z,1744044894.356 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T16:54:54.753Z,1744044894.753 [PowerOnly](INFO): Powering up loadControl
2025-04-07T16:54:54.807Z,1744044894.807 [lab_test_optim:Run:D] Stopped
2025-04-07T16:54:54.807Z,1744044894.807 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T16:54:54.807Z,1744044894.807 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T16:54:54.807Z,1744044894.807 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T16:54:54.807Z,1744044894.807 [lab_test_optim:D] Running Loop=1
2025-04-07T16:54:54.807Z,1744044894.807 [lab_test_optim:D] Running Loop=1
2025-04-07T16:54:54.808Z,1744044894.808 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T16:54:55.178Z,1744044895.178 [lab_test_optim:Run:setRed] Stopped
2025-04-07T16:54:55.178Z,1744044895.178 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T16:54:55.179Z,1744044895.179 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T16:54:55.179Z,1744044895.179 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T16:54:55.179Z,1744044895.179 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T16:54:55.179Z,1744044895.179 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T16:54:55.590Z,1744044895.590 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T16:54:55.590Z,1744044895.590 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T16:54:56.004Z,1744044896.004 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T16:54:56.004Z,1744044896.004 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T16:54:56.004Z,1744044896.004 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T16:54:56.004Z,1744044896.004 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T16:54:56.004Z,1744044896.004 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T16:54:56.004Z,1744044896.004 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T16:54:56.371Z,1744044896.371 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T16:54:56.371Z,1744044896.371 [lab_test_optim:Run:G] Stopped
2025-04-07T16:54:56.371Z,1744044896.371 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T16:54:56.371Z,1744044896.371 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:54:57.159Z,1744044897.159 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T16:55:21.095Z,1744044921.095 [BackseatComponent](IMPORTANT): ikshana: running backseat application.
2025-04-07T16:55:56.968Z,1744044956.968 [lab_test_optim:Run:H.Wait](INFO): Done Waiting.
2025-04-07T16:55:56.969Z,1744044956.969 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T16:55:56.969Z,1744044956.969 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T16:55:56.971Z,1744044956.971 [lab_test_optim:Run](INFO): Completed lab_test_optim:Run
2025-04-07T16:55:56.971Z,1744044956.971 [lab_test_optim:Run] Stopped
2025-04-07T16:55:56.971Z,1744044956.971 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T16:55:56.972Z,1744044956.972 [lab_test_optim:G.Wait] Running Loop=1
2025-04-07T16:55:56.972Z,1744044956.972 [lab_test_optim:G.Wait](DEBUG): Initialize Wait Component.
2025-04-07T16:56:28.463Z,1744044988.463 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-04-07T16:56:28.463Z,1744044988.463 [NAL9602] Data Fault, FailCount= 1
2025-04-07T16:56:28.463Z,1744044988.463 [NAL9602](ERROR): Data Fault
2025-04-07T16:56:28.489Z,1744044988.489 [CBIT](ERROR): Data Fault in component: NAL9602
2025-04-07T16:56:28.865Z,1744044988.865 [NAL9602](INFO): Powering down
2025-04-07T16:56:29.697Z,1744044989.697 [CBIT](INFO): Clearing failed state for component NAL9602
2025-04-07T16:56:29.697Z,1744044989.697 [NAL9602] No Fault, FailCount= 1
2025-04-07T16:56:59.176Z,1744045019.176 [NAL9602](INFO): Powering up NAL9602
2025-04-07T16:57:10.075Z,1744045030.075 [NAL9602](INFO): NAL9602 initialized
2025-04-07T16:57:50.906Z,1744045070.906 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-04-07T16:57:50.906Z,1744045070.906 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T16:57:50.917Z,1744045070.917 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T16:57:51.309Z,1744045071.309 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T16:57:51.309Z,1744045071.309 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-04-07T17:00:51.906Z,1744045251.906 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-04-07T17:00:51.906Z,1744045251.906 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T17:00:51.933Z,1744045251.933 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T17:00:52.358Z,1744045252.358 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T17:00:52.359Z,1744045252.359 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-04-07T17:02:35.792Z,1744045355.792 [BackseatComponent](CRITICAL): ikshana: Data dir size (57.03 GB) did not increase within 10 minutes
2025-04-07T17:02:35.792Z,1744045355.792 [BackseatComponent] Data Fault, FailCount= 1
2025-04-07T17:02:35.792Z,1744045355.792 [BackseatComponent](ERROR): Data Fault
2025-04-07T17:02:36.163Z,1744045356.163 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.data_dir_logging_rate with code: 1975
2025-04-07T17:02:36.194Z,1744045356.194 [CommandExec](FAULT): Scheduling is paused
2025-04-07T17:02:36.194Z,1744045356.194 [CBIT](INFO): Critical error at 20250407T170235
2025-04-07T17:02:36.194Z,1744045356.194 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-04-07T17:02:36.197Z,1744045356.197 [CBIT](ERROR): Data Fault in component: BackseatComponent
2025-04-07T17:02:36.198Z,1744045356.198 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T17:02:36.199Z,1744045356.199 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T17:02:36.569Z,1744045356.569 [MissionManager](INFO): MissionManager is completed.
2025-04-07T17:02:36.569Z,1744045356.569 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T17:02:36.569Z,1744045356.569 [lab_test_optim] Stopped
2025-04-07T17:02:36.569Z,1744045356.569 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T17:02:36.569Z,1744045356.569 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T17:02:36.570Z,1744045356.570 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T17:02:36.570Z,1744045356.570 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T17:02:36.570Z,1744045356.570 [lab_test_optim:B] Stopped
2025-04-07T17:02:36.570Z,1744045356.570 [lab_test_optim:C] Stopped
2025-04-07T17:02:36.570Z,1744045356.570 [lab_test_optim:D] Stopped
2025-04-07T17:02:36.570Z,1744045356.570 [lab_test_optim:G.Wait] Stopped
2025-04-07T17:02:36.570Z,1744045356.570 [lab_test_optim:G.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:02:36.964Z,1744045356.964 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T17:02:36.964Z,1744045356.964 [Default] Running Loop=1
2025-04-07T17:02:36.964Z,1744045356.964 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T17:02:36.965Z,1744045356.965 [Default:B.GoToSurface] Running Loop=1
2025-04-07T17:02:36.965Z,1744045356.965 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T17:02:36.965Z,1744045356.965 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T17:02:36.965Z,1744045356.965 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T17:02:36.966Z,1744045356.966 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T17:02:36.966Z,1744045356.966 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T17:02:36.966Z,1744045356.966 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T17:02:36.967Z,1744045356.967 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T17:02:36.967Z,1744045356.967 [Default:A.Wait] Running Loop=1
2025-04-07T17:02:36.967Z,1744045356.967 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:02:50.311Z,1744045370.311 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T17:02:50.311Z,1744045370.311 [Default:A.Wait] Stopped
2025-04-07T17:02:50.311Z,1744045370.311 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:02:50.711Z,1744045370.711 [Default:CheckIn] Running Loop=1
2025-04-07T17:02:50.711Z,1744045370.711 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:02:50.711Z,1744045370.711 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:02:54.389Z,1744045374.389 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T17:02:54.390Z,1744045374.390 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T17:02:54.390Z,1744045374.390 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T17:03:13.377Z,1744045393.377 [CBIT](INFO): Clearing failed state for component BackseatComponent
2025-04-07T17:03:13.377Z,1744045393.377 [BackseatComponent] No Fault, FailCount= 0
2025-04-07T17:03:13.408Z,1744045393.408 [BackseatComponent](INFO): Powering up
2025-04-07T17:03:13.408Z,1744045393.408 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T17:03:34.306Z,1744045414.306 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T17:03:34.307Z,1744045414.307 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T17:03:52.498Z,1744045432.498 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T17:03:52.498Z,1744045432.498 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T17:03:52.498Z,1744045432.498 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T17:03:52.919Z,1744045432.919 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-04-07T17:03:52.919Z,1744045432.919 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T17:03:52.951Z,1744045432.951 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T17:03:53.364Z,1744045433.364 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T17:03:53.364Z,1744045433.364 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-04-07T17:04:07.051Z,1744045447.051 [PowerOnly](INFO): Powering down loadControl
2025-04-07T17:05:07.611Z,1744045507.611 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.loadAtStartup
2025-04-07T17:05:07.612Z,1744045507.612 [CommandExec](IMPORTANT): Sonardyne_Nano.loadAtStartup 0 bool
2025-04-07T17:06:53.946Z,1744045613.946 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-04-07T17:06:53.946Z,1744045613.946 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T17:06:53.961Z,1744045613.961 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T17:06:54.371Z,1744045614.371 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T17:06:54.372Z,1744045614.372 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-04-07T17:07:10.891Z,1744045630.891 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-04-07T17:07:10.891Z,1744045630.891 [NAL9602] Data Fault, FailCount= 2
2025-04-07T17:07:10.891Z,1744045630.891 [NAL9602](ERROR): Data Fault
2025-04-07T17:07:10.909Z,1744045630.909 [CBIT](ERROR): Data Fault in component: NAL9602
2025-04-07T17:07:11.295Z,1744045631.295 [NAL9602](INFO): Powering down
2025-04-07T17:07:12.138Z,1744045632.138 [CBIT](INFO): Clearing failed state for component NAL9602
2025-04-07T17:07:12.138Z,1744045632.138 [NAL9602] No Fault, FailCount= 2
2025-04-07T17:07:13.902Z,1744045633.902 [CommandExec](IMPORTANT): got command failComponent
2025-04-07T17:07:13.902Z,1744045633.902 [CommandExec](IMPORTANT): Failed components:
2025-04-07T17:07:13.902Z,1744045633.902 [CommandExec](IMPORTANT): No failed Components.
2025-04-07T17:07:41.627Z,1744045661.627 [NAL9602](INFO): Powering up NAL9602
2025-04-07T17:07:50.926Z,1744045670.926 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-04-07T17:02:50.7Z
2025-04-07T17:07:50.927Z,1744045670.927 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:07:50.927Z,1744045670.927 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T17:07:51.333Z,1744045671.333 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-07T17:07:52.535Z,1744045672.535 [NAL9602](INFO): NAL9602 initialized
2025-04-07T17:07:58.658Z,1744045678.658 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20250407T164534/Courier0004.lzma
2025-04-07T17:07:59.659Z,1744045679.659 [DataOverHttps](INFO): Moved sent file to Logs/20250407T164534/Courier0004.lzma.bak
2025-04-07T17:07:59.659Z,1744045679.659 [DataOverHttps](INFO): SBD MOMSN=24561179
2025-04-07T17:08:15.522Z,1744045695.522 [DataOverHttps](INFO): Sending 724 bytes from file Logs/20250407T164534/Express0005.lzma
2025-04-07T17:08:16.523Z,1744045696.523 [DataOverHttps](INFO): Moved sent file to Logs/20250407T164534/Express0005.lzma.bak
2025-04-07T17:08:16.523Z,1744045696.523 [DataOverHttps](INFO): SBD MOMSN=24561195
2025-04-07T17:08:17.611Z,1744045697.611 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T17:08:17.612Z,1744045697.612 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T17:08:17.612Z,1744045697.612 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:20.292Z,1744045700.292 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/multiray_test.tl
2025-04-07T17:08:20.297Z,1744045700.297 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/multiray_test.tl
2025-04-07T17:08:20.297Z,1744045700.297 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/multiray_test.tl
2025-04-07T17:08:20.300Z,1744045700.300 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/multiray_test.tl
2025-04-07T17:08:20.776Z,1744045700.776 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/multiray_test.tl translated into:
5
5
0
1
2
2025-04-07T17:08:20.790Z,1744045700.790 [MissionManager](INFO): DefineArg multiray_test.MissionTimeout = 5.000000 min
2025-04-07T17:08:20.869Z,1744045700.869 [MissionManager](INFO): DefineArg multiray_test.LightDuration = 5.000000 s
2025-04-07T17:08:20.875Z,1744045700.875 [MissionManager](INFO): DefineArg multiray_test.LightMode0 = 0.000000 count
2025-04-07T17:08:20.886Z,1744045700.886 [MissionManager](INFO): DefineArg multiray_test.LightMode1 = 1.000000 count
2025-04-07T17:08:20.888Z,1744045700.888 [MissionManager](INFO): DefineArg multiray_test.LightMode2 = 2.000000 count
2025-04-07T17:08:20.908Z,1744045700.908 [MissionManager](INFO): DefineArg multiray_test.EnabledMultiray = 1 bool
2025-04-07T17:08:20.924Z,1744045700.924 [multiray_test:C.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:20.944Z,1744045700.944 [multiray_test:E.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:20.956Z,1744045700.956 [multiray_test:G.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:20.967Z,1744045700.967 [multiray_test:I.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:20.976Z,1744045700.976 [multiray_test:K.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:21.003Z,1744045701.003 [multiray_test:M.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:21.011Z,1744045701.011 [multiray_test:O.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:21.038Z,1744045701.038 [multiray_test:Q.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:21.050Z,1744045701.050 [multiray_test:R.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:21.061Z,1744045701.061 [multiray_test:T.Wait](DEBUG): Construct Wait.
2025-04-07T17:08:21.083Z,1744045701.083 [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 multiray_test {
"""
This mission is designed to run in the lab only. Cycles through MultiRay light modes
"""
arguments {
MissionTimeout = 5 minute
"""
How long to let the mission run.
"""
LightDuration = 5 second
"""
How long to wait before changing light modes
"""
LightMode0 = 0 count
"""
Light mode = 0
"""
LightMode1 = 1 count
"""
Light mode = 1
"""
LightMode2 = 2 count
"""
Light mode = 2
"""
EnabledMultiray = Sensor:MultiRay.loadAtStartup
"""
Automatically set to true if the Multiray is enabled.
"""
}
timeout duration=MissionTimeout
readData strategy="MinError" {
while ( EnabledMultiray )
Sensor:MultiRay.lightModeLog
}
#
#
#
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode0
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode1
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode2
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode0
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode1
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode2
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode0
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode1
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode2
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode0
behavior Guidance:Wait {
run in sequence
set duration = LightDuration
}
}
2025-04-07T17:08:21.084Z,1744045701.084 [CommandExec](IMPORTANT): Running ./Missions/Engineering/multiray_test.tl
2025-04-07T17:08:21.258Z,1744045701.258 [Default] Stopped
2025-04-07T17:08:21.258Z,1744045701.258 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T17:08:21.259Z,1744045701.259 [Default:B.GoToSurface] Stopped
2025-04-07T17:08:21.259Z,1744045701.259 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T17:08:21.259Z,1744045701.259 [Default:CheckIn] Stopped
2025-04-07T17:08:21.259Z,1744045701.259 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:08:21.259Z,1744045701.259 [Default:CheckIn:C.Wait] Stopped
2025-04-07T17:08:21.259Z,1744045701.259 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:08:21.259Z,1744045701.259 [MissionManager](IMPORTANT): Started mission multiray_test
2025-04-07T17:08:21.259Z,1744045701.259 [multiray_test] Running Loop=1
2025-04-07T17:08:21.259Z,1744045701.259 [multiray_test](DEBUG): Aggregate::initialize multiray_test
2025-04-07T17:08:21.259Z,1744045701.259 [multiray_test:A] Running Loop=1
2025-04-07T17:08:21.260Z,1744045701.260 [multiray_test:B] Running Loop=1
2025-04-07T17:08:21.260Z,1744045701.260 [multiray_test:B] Stopped
2025-04-07T17:08:21.260Z,1744045701.260 [multiray_test:C.Wait] Running Loop=1
2025-04-07T17:08:21.260Z,1744045701.260 [multiray_test:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:21.260Z,1744045701.260 [multiray_test:A] Running Loop=1
2025-04-07T17:08:21.265Z,1744045701.265 [multiray_test:A](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T17:08:22.830Z,1744045702.830 [MultiRay](IMPORTANT): MultiRay all lights OFF
2025-04-07T17:08:26.919Z,1744045706.919 [multiray_test:C.Wait](INFO): Done Waiting.
2025-04-07T17:08:26.919Z,1744045706.919 [multiray_test:C.Wait] Stopped
2025-04-07T17:08:26.919Z,1744045706.919 [multiray_test:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:08:26.920Z,1744045706.920 [multiray_test:D] Running Loop=1
2025-04-07T17:08:27.311Z,1744045707.311 [multiray_test:D] Stopped
2025-04-07T17:08:27.312Z,1744045707.312 [multiray_test:E.Wait] Running Loop=1
2025-04-07T17:08:27.312Z,1744045707.312 [multiray_test:E.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:29.723Z,1744045709.723 [MultiRay](IMPORTANT): Multiray red lights ON
2025-04-07T17:08:32.965Z,1744045712.965 [multiray_test:E.Wait](INFO): Done Waiting.
2025-04-07T17:08:32.965Z,1744045712.965 [multiray_test:E.Wait] Stopped
2025-04-07T17:08:32.966Z,1744045712.966 [multiray_test:E.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:08:32.966Z,1744045712.966 [multiray_test:F] Running Loop=1
2025-04-07T17:08:33.360Z,1744045713.360 [multiray_test:F] Stopped
2025-04-07T17:08:33.360Z,1744045713.360 [multiray_test:G.Wait] Running Loop=1
2025-04-07T17:08:33.360Z,1744045713.360 [multiray_test:G.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:34.986Z,1744045714.986 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T17:08:39.015Z,1744045719.015 [multiray_test:G.Wait](INFO): Done Waiting.
2025-04-07T17:08:39.015Z,1744045719.015 [multiray_test:G.Wait] Stopped
2025-04-07T17:08:39.015Z,1744045719.015 [multiray_test:G.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:08:39.016Z,1744045719.016 [multiray_test:H] Running Loop=1
2025-04-07T17:08:39.426Z,1744045719.426 [multiray_test:H] Stopped
2025-04-07T17:08:39.426Z,1744045719.426 [multiray_test:I.Wait] Running Loop=1
2025-04-07T17:08:39.427Z,1744045719.427 [multiray_test:I.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:40.214Z,1744045720.214 [MultiRay](IMPORTANT): MultiRay all lights OFF
2025-04-07T17:08:45.071Z,1744045725.071 [multiray_test:I.Wait](INFO): Done Waiting.
2025-04-07T17:08:45.071Z,1744045725.071 [multiray_test:I.Wait] Stopped
2025-04-07T17:08:45.071Z,1744045725.071 [multiray_test:I.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:08:45.071Z,1744045725.071 [multiray_test:J] Running Loop=1
2025-04-07T17:08:45.479Z,1744045725.479 [multiray_test:J] Stopped
2025-04-07T17:08:45.479Z,1744045725.479 [multiray_test:K.Wait] Running Loop=1
2025-04-07T17:08:45.479Z,1744045725.479 [multiray_test:K.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:47.891Z,1744045727.891 [MultiRay](IMPORTANT): Multiray red lights ON
2025-04-07T17:08:51.131Z,1744045731.131 [multiray_test:K.Wait](INFO): Done Waiting.
2025-04-07T17:08:51.131Z,1744045731.131 [multiray_test:K.Wait] Stopped
2025-04-07T17:08:51.131Z,1744045731.131 [multiray_test:K.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:08:51.131Z,1744045731.131 [multiray_test:L] Running Loop=1
2025-04-07T17:08:51.535Z,1744045731.535 [multiray_test:L] Stopped
2025-04-07T17:08:51.536Z,1744045731.536 [multiray_test:M.Wait] Running Loop=1
2025-04-07T17:08:51.536Z,1744045731.536 [multiray_test:M.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:53.142Z,1744045733.142 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T17:08:57.210Z,1744045737.210 [multiray_test:M.Wait](INFO): Done Waiting.
2025-04-07T17:08:57.210Z,1744045737.210 [multiray_test:M.Wait] Stopped
2025-04-07T17:08:57.210Z,1744045737.210 [multiray_test:M.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:08:57.211Z,1744045737.211 [multiray_test:N] Running Loop=1
2025-04-07T17:08:57.618Z,1744045737.618 [multiray_test:N] Stopped
2025-04-07T17:08:57.618Z,1744045737.618 [multiray_test:O.Wait] Running Loop=1
2025-04-07T17:08:57.618Z,1744045737.618 [multiray_test:O.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:08:58.399Z,1744045738.399 [MultiRay](IMPORTANT): MultiRay all lights OFF
2025-04-07T17:09:03.248Z,1744045743.248 [multiray_test:O.Wait](INFO): Done Waiting.
2025-04-07T17:09:03.248Z,1744045743.248 [multiray_test:O.Wait] Stopped
2025-04-07T17:09:03.248Z,1744045743.248 [multiray_test:O.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:09:03.248Z,1744045743.248 [multiray_test:P] Running Loop=1
2025-04-07T17:09:03.669Z,1744045743.669 [multiray_test:P] Stopped
2025-04-07T17:09:03.669Z,1744045743.669 [multiray_test:Q.Wait] Running Loop=1
2025-04-07T17:09:03.669Z,1744045743.669 [multiray_test:Q.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:09:06.071Z,1744045746.071 [MultiRay](IMPORTANT): Multiray red lights ON
2025-04-07T17:09:09.414Z,1744045749.414 [multiray_test:Q.Wait](INFO): Done Waiting.
2025-04-07T17:09:09.414Z,1744045749.414 [multiray_test:Q.Wait] Stopped
2025-04-07T17:09:09.415Z,1744045749.415 [multiray_test:Q.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:09:09.415Z,1744045749.415 [multiray_test:U] Running Loop=1
2025-04-07T17:09:09.712Z,1744045749.712 [multiray_test:U] Stopped
2025-04-07T17:09:09.712Z,1744045749.712 [multiray_test:R.Wait] Running Loop=1
2025-04-07T17:09:09.713Z,1744045749.713 [multiray_test:R.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:09:11.323Z,1744045751.323 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T17:09:15.371Z,1744045755.371 [multiray_test:R.Wait](INFO): Done Waiting.
2025-04-07T17:09:15.371Z,1744045755.371 [multiray_test:R.Wait] Stopped
2025-04-07T17:09:15.371Z,1744045755.371 [multiray_test:R.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:09:15.371Z,1744045755.371 [multiray_test:S] Running Loop=1
2025-04-07T17:09:15.773Z,1744045755.773 [multiray_test:S] Stopped
2025-04-07T17:09:15.773Z,1744045755.773 [multiray_test:T.Wait] Running Loop=1
2025-04-07T17:09:15.773Z,1744045755.773 [multiray_test:T.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:09:16.574Z,1744045756.574 [MultiRay](IMPORTANT): MultiRay all lights OFF
2025-04-07T17:09:21.438Z,1744045761.438 [multiray_test:T.Wait](INFO): Done Waiting.
2025-04-07T17:09:21.438Z,1744045761.438 [multiray_test:T.Wait] Stopped
2025-04-07T17:09:21.438Z,1744045761.438 [multiray_test:T.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:09:21.438Z,1744045761.438 [multiray_test](INFO): Completed multiray_test
2025-04-07T17:09:21.438Z,1744045761.438 [MissionManager](INFO): multiray_test is completed.
2025-04-07T17:09:21.438Z,1744045761.438 [MissionManager](INFO): Uninitializing Mission multiray_test
2025-04-07T17:09:21.438Z,1744045761.438 [multiray_test] Stopped
2025-04-07T17:09:21.439Z,1744045761.439 [multiray_test](DEBUG): Aggregate::uninitialize multiray_test
2025-04-07T17:09:21.439Z,1744045761.439 [multiray_test:A] Stopped
2025-04-07T17:09:21.851Z,1744045761.851 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T17:09:21.851Z,1744045761.851 [Default] Running Loop=1
2025-04-07T17:09:21.851Z,1744045761.851 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T17:09:21.851Z,1744045761.851 [Default:B.GoToSurface] Running Loop=1
2025-04-07T17:09:21.851Z,1744045761.851 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T17:09:21.852Z,1744045761.852 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T17:09:21.852Z,1744045761.852 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T17:09:21.852Z,1744045761.852 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T17:09:21.853Z,1744045761.853 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T17:09:21.853Z,1744045761.853 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T17:09:21.853Z,1744045761.853 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T17:09:21.854Z,1744045761.854 [Default:A.Wait] Running Loop=1
2025-04-07T17:09:21.854Z,1744045761.854 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:09:35.200Z,1744045775.200 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T17:09:35.200Z,1744045775.200 [Default:A.Wait] Stopped
2025-04-07T17:09:35.200Z,1744045775.200 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:09:35.588Z,1744045775.588 [Default:CheckIn] Running Loop=1
2025-04-07T17:09:35.589Z,1744045775.589 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:09:35.613Z,1744045775.613 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:09:54.959Z,1744045794.959 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-04-07T17:09:54.959Z,1744045794.959 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T17:09:54.969Z,1744045794.969 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T17:09:55.373Z,1744045795.373 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T17:09:55.374Z,1744045795.374 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-04-07T17:10:30.744Z,1744045830.744 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:10:30.745Z,1744045830.745 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:10:30.745Z,1744045830.745 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:10:30.747Z,1744045830.747 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:10:31.061Z,1744045831.061 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T17:10:31.066Z,1744045831.066 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T17:10:31.068Z,1744045831.068 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T17:10:31.070Z,1744045831.070 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T17:10:31.073Z,1744045831.073 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T17:10:31.075Z,1744045831.075 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T17:10:31.078Z,1744045831.078 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T17:10:31.080Z,1744045831.080 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T17:10:31.082Z,1744045831.082 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T17:10:31.082Z,1744045831.082 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T17:10:31.083Z,1744045831.083 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T17:10:31.084Z,1744045831.084 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T17:10:31.103Z,1744045831.103 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T17:10:31.106Z,1744045831.106 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T17:10:31.109Z,1744045831.109 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T17:10:31.191Z,1744045831.191 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T17:10:31.232Z,1744045831.232 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T17:10:31.236Z,1744045831.236 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T17:10:31.242Z,1744045831.242 [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
"""
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 {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
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 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-04-07T17:10:31.244Z,1744045831.244 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:10:31.348Z,1744045831.348 [Default] Stopped
2025-04-07T17:10:31.348Z,1744045831.348 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T17:10:31.348Z,1744045831.348 [Default:B.GoToSurface] Stopped
2025-04-07T17:10:31.348Z,1744045831.348 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T17:10:31.348Z,1744045831.348 [Default:CheckIn] Stopped
2025-04-07T17:10:31.348Z,1744045831.348 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:10:31.348Z,1744045831.348 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:10:31.348Z,1744045831.348 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim] Running Loop=1
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim:B] Running Loop=1
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim:C] Running Loop=1
2025-04-07T17:10:31.349Z,1744045831.349 [lab_test_optim:D] Running Loop=1
2025-04-07T17:10:31.350Z,1744045831.350 [lab_test_optim:Startup] Running Loop=1
2025-04-07T17:10:31.350Z,1744045831.350 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T17:10:31.350Z,1744045831.350 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:Startup:A] Stopped
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:D] Stopped
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:C] Stopped
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:B] Running Loop=1
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T17:10:31.351Z,1744045831.351 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T17:10:31.473Z,1744045831.473 [BackseatComponent](INFO): Powering up
2025-04-07T17:10:31.474Z,1744045831.474 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T17:11:02.031Z,1744045862.031 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T17:11:02.031Z,1744045862.031 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T17:11:02.031Z,1744045862.031 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:11:02.031Z,1744045862.031 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T17:11:02.031Z,1744045862.031 [lab_test_optim:Startup] Stopped
2025-04-07T17:11:02.031Z,1744045862.031 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T17:11:02.031Z,1744045862.031 [lab_test_optim:Run] Running Loop=1
2025-04-07T17:11:02.032Z,1744045862.032 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T17:11:02.032Z,1744045862.032 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T17:11:02.439Z,1744045862.439 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T17:11:02.439Z,1744045862.439 [lab_test_optim:Run:A] Stopped
2025-04-07T17:11:02.439Z,1744045862.439 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T17:11:02.836Z,1744045862.836 [lab_test_optim:Run:B] Stopped
2025-04-07T17:11:02.836Z,1744045862.836 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T17:11:03.239Z,1744045863.239 [lab_test_optim:Run:C] Stopped
2025-04-07T17:11:03.239Z,1744045863.239 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T17:11:03.239Z,1744045863.239 [lab_test_optim:C] Running Loop=1
2025-04-07T17:11:03.239Z,1744045863.239 [lab_test_optim:C] Running Loop=1
2025-04-07T17:11:03.240Z,1744045863.240 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T17:11:03.650Z,1744045863.650 [PowerOnly](INFO): Powering up loadControl
2025-04-07T17:11:03.704Z,1744045863.704 [lab_test_optim:Run:D] Stopped
2025-04-07T17:11:03.704Z,1744045863.704 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T17:11:03.704Z,1744045863.704 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T17:11:03.704Z,1744045863.704 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T17:11:03.705Z,1744045863.705 [lab_test_optim:D] Running Loop=1
2025-04-07T17:11:03.705Z,1744045863.705 [lab_test_optim:D] Running Loop=1
2025-04-07T17:11:03.705Z,1744045863.705 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T17:11:04.070Z,1744045864.070 [lab_test_optim:Run:setRed] Stopped
2025-04-07T17:11:04.070Z,1744045864.070 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T17:11:04.070Z,1744045864.070 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T17:11:04.071Z,1744045864.071 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T17:11:04.071Z,1744045864.071 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T17:11:04.071Z,1744045864.071 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T17:11:04.523Z,1744045864.523 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T17:11:04.523Z,1744045864.523 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T17:11:04.915Z,1744045864.915 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T17:11:04.915Z,1744045864.915 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T17:11:04.916Z,1744045864.916 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T17:11:04.916Z,1744045864.916 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T17:11:04.916Z,1744045864.916 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T17:11:04.916Z,1744045864.916 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T17:11:05.265Z,1744045865.265 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T17:11:05.265Z,1744045865.265 [lab_test_optim:Run:G] Stopped
2025-04-07T17:11:05.265Z,1744045865.265 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T17:11:05.265Z,1744045865.265 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:11:06.060Z,1744045866.060 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T17:11:09.674Z,1744045869.674 [CommandExec](IMPORTANT): got command stop
2025-04-07T17:11:09.674Z,1744045869.674 [CommandExec](IMPORTANT): Scheduling is paused
2025-04-07T17:11:09.674Z,1744045869.674 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T17:11:09.709Z,1744045869.709 [MissionManager](INFO): MissionManager is completed.
2025-04-07T17:11:09.709Z,1744045869.709 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T17:11:09.709Z,1744045869.709 [lab_test_optim] Stopped
2025-04-07T17:11:09.709Z,1744045869.709 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T17:11:09.709Z,1744045869.709 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:B] Stopped
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:C] Stopped
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:D] Stopped
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:Run] Stopped
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T17:11:09.710Z,1744045869.710 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:11:09.850Z,1744045869.850 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T17:11:09.851Z,1744045869.851 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T17:11:10.111Z,1744045870.111 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T17:11:10.111Z,1744045870.111 [Default] Running Loop=1
2025-04-07T17:11:10.111Z,1744045870.111 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T17:11:10.112Z,1744045870.112 [Default:B.GoToSurface] Running Loop=1
2025-04-07T17:11:10.112Z,1744045870.112 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T17:11:10.112Z,1744045870.112 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T17:11:10.112Z,1744045870.112 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T17:11:10.112Z,1744045870.112 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T17:11:10.113Z,1744045870.113 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T17:11:10.113Z,1744045870.113 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T17:11:10.114Z,1744045870.114 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T17:11:10.114Z,1744045870.114 [Default:A.Wait] Running Loop=1
2025-04-07T17:11:10.114Z,1744045870.114 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:11:23.450Z,1744045883.450 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T17:11:23.450Z,1744045883.450 [Default:A.Wait] Stopped
2025-04-07T17:11:23.451Z,1744045883.451 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:11:23.845Z,1744045883.845 [Default:CheckIn] Running Loop=1
2025-04-07T17:11:23.845Z,1744045883.845 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:11:23.846Z,1744045883.846 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:11:28.010Z,1744045888.010 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T17:11:28.011Z,1744045888.011 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T17:11:28.011Z,1744045888.011 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T17:12:40.201Z,1744045960.201 [PowerOnly](INFO): Powering down loadControl
2025-04-07T17:12:55.962Z,1744045975.962 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-04-07T17:12:55.962Z,1744045975.962 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T17:12:55.992Z,1744045975.992 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T17:12:56.370Z,1744045976.370 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T17:12:56.370Z,1744045976.370 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-04-07T17:15:07.348Z,1744046107.348 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:15:07.350Z,1744046107.350 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:15:07.351Z,1744046107.351 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:15:07.352Z,1744046107.352 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:15:07.622Z,1744046107.622 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T17:15:07.627Z,1744046107.627 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T17:15:07.629Z,1744046107.629 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T17:15:07.632Z,1744046107.632 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T17:15:07.634Z,1744046107.634 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T17:15:07.636Z,1744046107.636 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T17:15:07.638Z,1744046107.638 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T17:15:07.640Z,1744046107.640 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T17:15:07.643Z,1744046107.643 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T17:15:07.643Z,1744046107.643 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T17:15:07.643Z,1744046107.643 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T17:15:07.644Z,1744046107.644 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T17:15:07.664Z,1744046107.664 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T17:15:07.667Z,1744046107.667 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T17:15:07.717Z,1744046107.717 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T17:15:07.750Z,1744046107.750 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T17:15:07.835Z,1744046107.835 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T17:15:07.848Z,1744046107.848 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T17:15:07.858Z,1744046107.858 [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
"""
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 {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
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 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-04-07T17:15:07.874Z,1744046107.874 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:15:08.123Z,1744046108.123 [Default] Stopped
2025-04-07T17:15:08.123Z,1744046108.123 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T17:15:08.123Z,1744046108.123 [Default:B.GoToSurface] Stopped
2025-04-07T17:15:08.123Z,1744046108.123 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T17:15:08.123Z,1744046108.123 [Default:CheckIn] Stopped
2025-04-07T17:15:08.123Z,1744046108.123 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:15:08.123Z,1744046108.123 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:15:08.123Z,1744046108.123 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim] Running Loop=1
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:B] Running Loop=1
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:C] Running Loop=1
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:D] Running Loop=1
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:Startup] Running Loop=1
2025-04-07T17:15:08.124Z,1744046108.124 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T17:15:08.125Z,1744046108.125 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:Startup:A] Stopped
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:D] Stopped
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:C] Stopped
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:B] Running Loop=1
2025-04-07T17:15:08.126Z,1744046108.126 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T17:15:08.127Z,1744046108.127 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T17:15:08.145Z,1744046108.145 [BackseatComponent](INFO): Powering up
2025-04-07T17:15:08.146Z,1744046108.146 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T17:15:20.474Z,1744046120.474 [CommandExec](IMPORTANT): got command stop
2025-04-07T17:15:20.474Z,1744046120.474 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T17:15:20.649Z,1744046120.649 [MissionManager](INFO): MissionManager is completed.
2025-04-07T17:15:20.649Z,1744046120.649 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T17:15:20.649Z,1744046120.649 [lab_test_optim] Stopped
2025-04-07T17:15:20.649Z,1744046120.649 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T17:15:20.649Z,1744046120.649 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T17:15:20.650Z,1744046120.650 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T17:15:20.650Z,1744046120.650 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T17:15:20.650Z,1744046120.650 [lab_test_optim:B] Stopped
2025-04-07T17:15:20.650Z,1744046120.650 [lab_test_optim:Startup] Stopped
2025-04-07T17:15:20.650Z,1744046120.650 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T17:15:20.650Z,1744046120.650 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T17:15:20.650Z,1744046120.650 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:15:21.038Z,1744046121.038 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T17:15:21.039Z,1744046121.039 [Default] Running Loop=1
2025-04-07T17:15:21.039Z,1744046121.039 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T17:15:21.039Z,1744046121.039 [Default:B.GoToSurface] Running Loop=1
2025-04-07T17:15:21.039Z,1744046121.039 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T17:15:21.039Z,1744046121.039 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T17:15:21.039Z,1744046121.039 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T17:15:21.040Z,1744046121.040 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T17:15:21.040Z,1744046121.040 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T17:15:21.040Z,1744046121.040 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T17:15:21.041Z,1744046121.041 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T17:15:21.041Z,1744046121.041 [Default:A.Wait] Running Loop=1
2025-04-07T17:15:21.041Z,1744046121.041 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:15:29.026Z,1744046129.026 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T17:15:29.027Z,1744046129.027 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T17:15:34.402Z,1744046134.402 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T17:15:34.402Z,1744046134.402 [Default:A.Wait] Stopped
2025-04-07T17:15:34.402Z,1744046134.402 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:15:34.812Z,1744046134.812 [Default:CheckIn] Running Loop=1
2025-04-07T17:15:34.812Z,1744046134.812 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T17:15:34.812Z,1744046134.812 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T17:15:47.038Z,1744046147.038 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T17:15:47.038Z,1744046147.038 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T17:15:47.038Z,1744046147.038 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T17:15:57.018Z,1744046157.018 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2025-04-07T17:15:57.018Z,1744046157.018 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T17:15:57.029Z,1744046157.029 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T17:15:57.436Z,1744046157.436 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T17:15:57.436Z,1744046157.436 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2025-04-07T17:16:05.959Z,1744046165.959 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T171604
2025-04-07T17:16:13.953Z,1744046173.953 [DataOverHttps](INFO): Received command: load Engineering/lab_test_optim.tl;set lab_test_optim.RecordTime 13 min;set lab_test_optim.LightMode 0 count;run
2025-04-07T17:16:14.079Z,1744046174.079 [CommandExec](IMPORTANT): got command load ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:16:14.079Z,1744046174.079 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:16:14.080Z,1744046174.080 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:16:14.083Z,1744046174.083 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T17:16:14.339Z,1744046174.339 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T17:16:14.343Z,1744046174.343 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T17:16:14.394Z,1744046174.394 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T17:16:14.396Z,1744046174.396 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T17:16:14.430Z,1744046174.430 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T17:16:14.432Z,1744046174.432 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T17:16:14.443Z,1744046174.443 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T17:16:14.469Z,1744046174.469 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T17:16:14.471Z,1744046174.471 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T17:16:14.472Z,1744046174.472 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T17:16:14.472Z,1744046174.472 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T17:16:14.489Z,1744046174.489 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T17:16:14.562Z,1744046174.562 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T17:16:14.565Z,1744046174.565 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T17:16:14.570Z,1744046174.570 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T17:16:14.578Z,1744046174.578 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T17:16:14.593Z,1744046174.593 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T17:16:14.595Z,1744046174.595 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T17:16:14.600Z,1744046174.600 [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
"""
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 {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
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 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-04-07T17:16:14.601Z,1744046174.601 [CommandExec](IMPORTANT): Loaded ./Missions/Engineering/lab_test_optim.tl id=lab_test_optim
2025-04-07T17:16:20.789Z,1744046180.789 [CommandExec](IMPORTANT): got command set lab_test_optim.RecordTime 13 minute
2025-04-07T17:16:20.790Z,1744046180.790 [CommandExec](IMPORTANT): got command set lab_test_optim.LightMode 0 count
2025-04-07T17:16:20.790Z,1744046180.790 [CommandExec](IMPORTANT): got command run
2025-04-07T17:16:20.792Z,1744046180.792 [CommandExec](IMPORTANT): Running
2025-04-07T17:16:20.878Z,1744046180.878 [Default] Stopped
2025-04-07T17:16:20.878Z,1744046180.878 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T17:16:20.878Z,1744046180.878 [Default:B.GoToSurface] Stopped
2025-04-07T17:16:20.878Z,1744046180.878 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T17:16:20.878Z,1744046180.878 [Default:CheckIn] Stopped
2025-04-07T17:16:20.878Z,1744046180.878 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T17:16:20.878Z,1744046180.878 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T17:16:20.878Z,1744046180.878 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim] Running Loop=1
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim:B] Running Loop=1
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim:C] Running Loop=1
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim:D] Running Loop=1
2025-04-07T17:16:20.879Z,1744046180.879 [lab_test_optim:Startup] Running Loop=1
2025-04-07T17:16:20.880Z,1744046180.880 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T17:16:20.880Z,1744046180.880 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T17:16:20.880Z,1744046180.880 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T17:16:20.880Z,1744046180.880 [lab_test_optim:Startup:A] Stopped
2025-04-07T17:16:20.881Z,1744046180.881 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T17:16:20.881Z,1744046180.881 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:16:20.885Z,1744046180.885 [lab_test_optim:D] Stopped
2025-04-07T17:16:20.885Z,1744046180.885 [lab_test_optim:C] Stopped
2025-04-07T17:16:20.885Z,1744046180.885 [lab_test_optim:B] Running Loop=1
2025-04-07T17:16:20.885Z,1744046180.885 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T17:16:20.886Z,1744046180.886 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T17:16:20.941Z,1744046180.941 [BackseatComponent](INFO): Powering up
2025-04-07T17:16:20.942Z,1744046180.942 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Startup] Stopped
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Run] Running Loop=1
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T17:16:51.560Z,1744046211.560 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T17:16:51.971Z,1744046211.971 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T17:16:51.971Z,1744046211.971 [lab_test_optim:Run:A] Stopped
2025-04-07T17:16:51.971Z,1744046211.971 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T17:16:52.395Z,1744046212.395 [lab_test_optim:Run:B] Stopped
2025-04-07T17:16:52.395Z,1744046212.395 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T17:16:52.804Z,1744046212.804 [lab_test_optim:Run:C] Stopped
2025-04-07T17:16:52.804Z,1744046212.804 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T17:16:52.804Z,1744046212.804 [lab_test_optim:C] Running Loop=1
2025-04-07T17:16:52.804Z,1744046212.804 [lab_test_optim:C] Running Loop=1
2025-04-07T17:16:52.804Z,1744046212.804 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T17:16:53.178Z,1744046213.178 [PowerOnly](INFO): Powering up loadControl
2025-04-07T17:16:53.207Z,1744046213.207 [lab_test_optim:Run:D] Stopped
2025-04-07T17:16:53.207Z,1744046213.207 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T17:16:53.208Z,1744046213.208 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T17:16:53.208Z,1744046213.208 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T17:16:53.208Z,1744046213.208 [lab_test_optim:D] Running Loop=1
2025-04-07T17:16:53.208Z,1744046213.208 [lab_test_optim:D] Running Loop=1
2025-04-07T17:16:53.208Z,1744046213.208 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T17:16:53.588Z,1744046213.588 [lab_test_optim:Run:setRed] Stopped
2025-04-07T17:16:53.589Z,1744046213.589 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T17:16:53.589Z,1744046213.589 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T17:16:53.589Z,1744046213.589 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T17:16:53.589Z,1744046213.589 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T17:16:53.589Z,1744046213.589 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T17:16:54.023Z,1744046214.023 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T17:16:54.024Z,1744046214.024 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T17:16:54.024Z,1744046214.024 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T17:16:54.024Z,1744046214.024 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T17:16:54.432Z,1744046214.432 [lab_test_optim:Run:G](IMPORTANT): Recording for 13.000000 min
2025-04-07T17:16:54.432Z,1744046214.432 [lab_test_optim:Run:G] Stopped
2025-04-07T17:16:54.432Z,1744046214.432 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T17:16:54.432Z,1744046214.432 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:16:54.804Z,1744046214.804 [MultiRay](IMPORTANT): MultiRay all lights OFF
2025-04-07T17:17:19.247Z,1744046239.247 [BackseatComponent](IMPORTANT): ikshana: running backseat application.
2025-04-07T17:17:54.171Z,1744046274.171 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-04-07T17:17:54.171Z,1744046274.171 [NAL9602] Data Fault, FailCount= 3
2025-04-07T17:17:54.171Z,1744046274.171 [NAL9602](ERROR): Data Fault
2025-04-07T17:17:54.189Z,1744046274.189 [CBIT](ERROR): Data Fault in component: NAL9602
2025-04-07T17:17:54.575Z,1744046274.575 [NAL9602](INFO): Powering down
2025-04-07T17:17:55.427Z,1744046275.427 [CBIT](INFO): Clearing failed state for component NAL9602
2025-04-07T17:17:55.427Z,1744046275.427 [NAL9602] No Fault, FailCount= 3
2025-04-07T17:18:24.883Z,1744046304.883 [NAL9602](INFO): Powering up NAL9602
2025-04-07T17:18:35.783Z,1744046315.783 [NAL9602](INFO): NAL9602 initialized
2025-04-07T17:18:58.031Z,1744046338.031 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2025-04-07T17:18:58.031Z,1744046338.031 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T17:18:58.046Z,1744046338.046 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T17:18:58.445Z,1744046338.445 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T17:18:58.445Z,1744046338.445 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2025-04-07T17:20:20.400Z,1744046420.400 [CommandExec](IMPORTANT): got command get CBIT.stopDepth
2025-04-07T17:20:20.400Z,1744046420.400 [CommandExec](IMPORTANT): CBIT.stopDepth 290.000000 m
2025-04-07T17:20:22.749Z,1744046422.749 [CommandExec](IMPORTANT): got command get CBIT.abortDepth
2025-04-07T17:20:22.750Z,1744046422.750 [CommandExec](IMPORTANT): CBIT.abortDepth 300.000000 m
2025-04-07T17:20:31.075Z,1744046431.075 [CommandExec](IMPORTANT): got command restart application
2025-04-07T17:20:32.077Z,1744046432.077 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2025-04-07T17:20:32.077Z,1744046432.077 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:32.078Z,1744046432.078 [CommandExec](INFO): Uninitializing the command executive.
2025-04-07T17:20:32.078Z,1744046432.078 [CommandExec](INFO): Uninitializing the command scheduler.
2025-04-07T17:20:32.078Z,1744046432.078 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:32.198Z,1744046432.198 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2025-04-07T17:20:32.198Z,1744046432.198 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2025-04-07T17:20:32.199Z,1744046432.199 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:32.199Z,1744046432.199 [NavChartDb](INFO): Join timeout helper Thread ID is 1179
2025-04-07T17:20:32.253Z,1744046432.253 [MissionManager](INFO): MissionManager is completed.
2025-04-07T17:20:32.253Z,1744046432.253 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T17:20:32.253Z,1744046432.253 [lab_test_optim] Stopped
2025-04-07T17:20:32.253Z,1744046432.253 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:B] Stopped
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:C] Stopped
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:D] Stopped
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:Run] Stopped
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T17:20:32.254Z,1744046432.254 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:20:32.449Z,1744046432.449 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:32.449Z,1744046432.449 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:32.461Z,1744046432.461 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2025-04-07T17:20:32.461Z,1744046432.461 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:32.461Z,1744046432.461 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1180
2025-04-07T17:20:32.597Z,1744046432.597 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:32.598Z,1744046432.598 [WetLabsBB2FL](INFO): Powering down
2025-04-07T17:20:32.598Z,1744046432.598 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:32.613Z,1744046432.613 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2025-04-07T17:20:32.613Z,1744046432.613 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:32.615Z,1744046432.615 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1181
2025-04-07T17:20:32.630Z,1744046432.630 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T17:20:32.630Z,1744046432.630 [Default] Running Loop=1
2025-04-07T17:20:32.630Z,1744046432.630 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T17:20:32.630Z,1744046432.630 [Default:B.GoToSurface] Running Loop=1
2025-04-07T17:20:32.630Z,1744046432.630 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T17:20:32.631Z,1744046432.631 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T17:20:32.631Z,1744046432.631 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T17:20:32.631Z,1744046432.631 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T17:20:32.631Z,1744046432.631 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T17:20:32.632Z,1744046432.632 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T17:20:32.632Z,1744046432.632 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T17:20:32.633Z,1744046432.633 [Default:A.Wait] Running Loop=1
2025-04-07T17:20:32.633Z,1744046432.633 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T17:20:33.118Z,1744046433.118 [CTD_Seabird](INFO): Powering down
2025-04-07T17:20:33.129Z,1744046433.129 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:33.129Z,1744046433.129 [CTD_Seabird](INFO): Powering down
2025-04-07T17:20:33.141Z,1744046433.141 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:33.153Z,1744046433.153 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2025-04-07T17:20:33.153Z,1744046433.153 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:33.153Z,1744046433.153 [Radio_Surface](INFO): Join timeout helper Thread ID is 1183
2025-04-07T17:20:33.185Z,1744046433.185 [Radio_Surface](INFO): Powering down
2025-04-07T17:20:33.186Z,1744046433.186 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:33.187Z,1744046433.187 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:33.202Z,1744046433.202 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2025-04-07T17:20:33.202Z,1744046433.202 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:33.203Z,1744046433.203 [Onboard](INFO): Join timeout helper Thread ID is 1184
2025-04-07T17:20:33.554Z,1744046433.554 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T17:20:33.555Z,1744046433.555 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T17:20:33.717Z,1744046433.717 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-04-07T17:20:34.949Z,1744046434.949 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:34.949Z,1744046434.949 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:34.958Z,1744046434.958 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2025-04-07T17:20:34.958Z,1744046434.958 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:34.958Z,1744046434.958 [DataOverHttps](INFO): Join timeout helper Thread ID is 1185
2025-04-07T17:20:35.726Z,1744046435.726 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:35.726Z,1744046435.726 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:35.746Z,1744046435.746 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2025-04-07T17:20:35.746Z,1744046435.746 [DAT ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:35.746Z,1744046435.746 [DAT](INFO): Join timeout helper Thread ID is 1186
2025-04-07T17:20:35.897Z,1744046435.897 [DAT](INFO): Powering down
2025-04-07T17:20:35.974Z,1744046435.974 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:35.974Z,1744046435.974 [DAT](INFO): Powering down
2025-04-07T17:20:35.975Z,1744046435.975 [DAT ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:35.994Z,1744046435.994 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2025-04-07T17:20:35.994Z,1744046435.994 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:35.994Z,1744046435.994 [BackseatComponent](INFO): Join timeout helper Thread ID is 1187
2025-04-07T17:20:36.001Z,1744046436.001 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:36.002Z,1744046436.002 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.014Z,1744046436.014 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2025-04-07T17:20:36.014Z,1744046436.014 [logger ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.014Z,1744046436.014 [logger](INFO): Join timeout helper Thread ID is 1188
2025-04-07T17:20:36.054Z,1744046436.054 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:36.054Z,1744046436.054 [logger ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.066Z,1744046436.066 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2025-04-07T17:20:36.066Z,1744046436.066 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.066Z,1744046436.066 [CommandLine](INFO): Join timeout helper Thread ID is 1189
2025-04-07T17:20:36.069Z,1744046436.069 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:36.070Z,1744046436.070 [CommandLine ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.086Z,1744046436.086 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2025-04-07T17:20:36.086Z,1744046436.086 [CommandExec ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.086Z,1744046436.086 [CommandExec](INFO): Join timeout helper Thread ID is 1190
2025-04-07T17:20:36.087Z,1744046436.087 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2025-04-07T17:20:36.087Z,1744046436.087 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.088Z,1744046436.088 [controlThread](INFO): Join timeout helper Thread ID is 1191
2025-04-07T17:20:36.229Z,1744046436.229 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2025-04-07T17:20:36.229Z,1744046436.229 [controlThread](DEBUG): Uninitializing ControlThread
2025-04-07T17:20:36.230Z,1744046436.230 [AHRS_M2](INFO): Powering down
2025-04-07T17:20:36.310Z,1744046436.310 [MultiRay](INFO): Powering down.
2025-04-07T17:20:36.311Z,1744046436.311 [NAL9602](INFO): Powering down
2025-04-07T17:20:36.312Z,1744046436.312 [Waterlinked](INFO): Powering down
2025-04-07T17:20:36.314Z,1744046436.314 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2025-04-07T17:20:36.315Z,1744046436.315 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2025-04-07T17:20:36.315Z,1744046436.315 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2025-04-07T17:20:36.316Z,1744046436.316 [MissionManager](INFO): Uninitializing Mission Default
2025-04-07T17:20:36.316Z,1744046436.316 [Default] Stopped
2025-04-07T17:20:36.316Z,1744046436.316 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T17:20:36.316Z,1744046436.316 [Default:A.Wait] Stopped
2025-04-07T17:20:36.316Z,1744046436.316 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T17:20:36.316Z,1744046436.316 [Default:B.GoToSurface] Stopped
2025-04-07T17:20:36.316Z,1744046436.316 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T17:20:36.319Z,1744046436.319 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2025-04-07T17:20:36.320Z,1744046436.320 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2025-04-07T17:20:36.320Z,1744046436.320 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2025-04-07T17:20:36.320Z,1744046436.320 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2025-04-07T17:20:36.320Z,1744046436.320 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-04-07T17:20:36.321Z,1744046436.321 [BuoyancyServo](INFO): Powering down
2025-04-07T17:20:36.333Z,1744046436.333 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2025-04-07T17:20:36.333Z,1744046436.333 [ElevatorServo](INFO): Powering down
2025-04-07T17:20:36.334Z,1744046436.334 [MassServo](DEBUG): Uninitialize Mass Servo.
2025-04-07T17:20:36.334Z,1744046436.334 [MassServo](INFO): Powering down
2025-04-07T17:20:36.335Z,1744046436.335 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2025-04-07T17:20:36.335Z,1744046436.335 [RudderServo](INFO): Powering down
2025-04-07T17:20:36.336Z,1744046436.336 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-04-07T17:20:36.336Z,1744046436.336 [ThrusterHE](INFO): Powering down
2025-04-07T17:20:36.337Z,1744046436.337 [SBIT](DEBUG): Uninitialize SBIT Component.
2025-04-07T17:20:36.337Z,1744046436.337 [IBIT](DEBUG): Uninitialize IBIT Component.
2025-04-07T17:20:36.338Z,1744046436.338 [CBIT](DEBUG): Uninitialize CBIT Component.
2025-04-07T17:20:36.338Z,1744046436.338 [CBIT](DEBUG): Powering off loads.
2025-04-07T17:20:36.349Z,1744046436.349 [CBIT](DEBUG): Disabling WDT.
2025-04-07T17:20:36.361Z,1744046436.361 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-04-07T17:20:36.361Z,1744046436.361 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-04-07T17:20:36.362Z,1744046436.362 [controlThread ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.393Z,1744046436.393 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.397Z,1744046436.397 [Onboard ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.404Z,1744046436.404 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.411Z,1744046436.411 [DAT ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.457Z,1744046436.457 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.539Z,1744046436.539 [GFScanner](DEBUG): Uninitialize GFScanner component.
2025-04-07T17:20:36.539Z,1744046436.539 [GFScanner](DEBUG): Opening all GF detection circuits.
2025-04-07T17:20:36.570Z,1744046436.570 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.575Z,1744046436.575 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.633Z,1744046436.633 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2025-04-07T17:20:36.682Z,1744046436.682 [logger ThreadHandler](INFO): Thread cancelled.