2025-03-06T18:03:34.139Z,1741284214.139 [Supervisor](DEBUG): Initializing supervisor.
2025-03-06T18:03:34.144Z,1741284214.144 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-03-06T18:03:34.145Z,1741284214.145 [SyncHandler](INFO): Protected caller Thread ID is 998
2025-03-06T18:03:34.145Z,1741284214.145 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-03-06T18:03:34.146Z,1741284214.146 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-03-06T18:03:34.147Z,1741284214.147 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 999
2025-03-06T18:03:34.151Z,1741284214.151 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-03-06T18:03:34.170Z,1741284214.170 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-03-06T18:03:34.171Z,1741284214.171 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-03-06T18:03:34.172Z,1741284214.172 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1000
2025-03-06T18:03:34.176Z,1741284214.176 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-03-06T18:03:34.177Z,1741284214.177 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-03-06T18:03:34.177Z,1741284214.177 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1001
2025-03-06T18:03:34.179Z,1741284214.179 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-03-06T18:03:34.180Z,1741284214.180 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-03-06T18:03:34.181Z,1741284214.181 [logger ThreadHandler](INFO): Protected caller Thread ID is 1002
2025-03-06T18:03:34.185Z,1741284214.185 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-03-06T18:03:34.185Z,1741284214.185 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-03-06T18:03:34.187Z,1741284214.187 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-03-06T18:03:34.408Z,1741284214.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-03-06T18:03:34.409Z,1741284214.409 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-03-06T18:03:34.526Z,1741284214.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-03-06T18:03:34.526Z,1741284214.526 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-03-06T18:03:34.632Z,1741284214.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-03-06T18:03:34.632Z,1741284214.632 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-03-06T18:03:35.133Z,1741284215.133 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-03-06T18:03:35.134Z,1741284215.134 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-03-06T18:03:35.496Z,1741284215.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-03-06T18:03:35.496Z,1741284215.496 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-03-06T18:03:35.853Z,1741284215.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-03-06T18:03:35.854Z,1741284215.854 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-03-06T18:03:36.053Z,1741284216.053 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-03-06T18:03:36.053Z,1741284216.053 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-03-06T18:03:36.143Z,1741284216.143 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-03-06T18:03:36.235Z,1741284216.235 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-03-06T18:03:36.682Z,1741284216.682 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-03-06T18:03:36.683Z,1741284216.683 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-03-06T18:03:36.987Z,1741284216.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-03-06T18:03:36.988Z,1741284216.988 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-03-06T18:03:37.567Z,1741284217.567 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-03-06T18:03:37.568Z,1741284217.568 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-03-06T18:03:37.825Z,1741284217.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-03-06T18:03:37.825Z,1741284217.825 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-03-06T18:03:38.083Z,1741284218.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-03-06T18:03:38.083Z,1741284218.083 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-03-06T18:03:38.235Z,1741284218.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-03-06T18:03:38.235Z,1741284218.235 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-03-06T18:03:39.685Z,1741284219.685 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-03-06T18:03:39.687Z,1741284219.687 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2025-03-06T18:03:39.688Z,1741284219.688 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2025-03-06T18:03:39.782Z,1741284219.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2025-03-06T18:03:39.920Z,1741284219.920 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2025-03-06T18:03:40.199Z,1741284220.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-03-06T18:03:40.200Z,1741284220.200 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2025-03-06T18:03:40.334Z,1741284220.334 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2025-03-06T18:03:40.440Z,1741284220.440 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2025-03-06T18:03:40.543Z,1741284220.543 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2025-03-06T18:03:40.660Z,1741284220.660 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2025-03-06T18:03:40.754Z,1741284220.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2025-03-06T18:03:40.850Z,1741284220.850 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2025-03-06T18:03:40.953Z,1741284220.953 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2025-03-06T18:03:41.132Z,1741284221.132 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2025-03-06T18:03:41.132Z,1741284221.132 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-03-06T18:03:41.142Z,1741284221.142 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-03-06T18:03:41.195Z,1741284221.195 [DepthRateCalculator] Loaded
2025-03-06T18:03:41.195Z,1741284221.195 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-03-06T18:03:41.201Z,1741284221.201 [PitchRateCalculator] Loaded
2025-03-06T18:03:41.201Z,1741284221.201 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-03-06T18:03:41.211Z,1741284221.211 [SpeedCalculator] Loaded
2025-03-06T18:03:41.211Z,1741284221.211 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-03-06T18:03:41.216Z,1741284221.216 [YawRateCalculator] Loaded
2025-03-06T18:03:41.217Z,1741284221.217 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-03-06T18:03:41.239Z,1741284221.239 [ElevatorOffsetCalculator] Loaded
2025-03-06T18:03:41.239Z,1741284221.239 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-03-06T18:03:41.239Z,1741284221.239 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-03-06T18:03:41.240Z,1741284221.240 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-03-06T18:03:41.269Z,1741284221.269 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-03-06T18:03:41.270Z,1741284221.270 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-03-06T18:03:41.280Z,1741284221.280 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-03-06T18:03:41.281Z,1741284221.281 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-03-06T18:03:41.788Z,1741284221.788 [AHRS_M2] Loaded
2025-03-06T18:03:41.788Z,1741284221.788 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-03-06T18:03:41.827Z,1741284221.827 [BackseatComponent] Loaded
2025-03-06T18:03:41.827Z,1741284221.827 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-03-06T18:03:41.828Z,1741284221.828 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408744E0
2025-03-06T18:03:41.829Z,1741284221.829 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1084
2025-03-06T18:03:41.832Z,1741284221.832 [LcmUniversalReporter] Loaded
2025-03-06T18:03:41.832Z,1741284221.832 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-03-06T18:03:42.652Z,1741284222.652 [BPC1] Loaded
2025-03-06T18:03:42.653Z,1741284222.653 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-03-06T18:03:42.728Z,1741284222.728 [DataOverHttps] Loaded
2025-03-06T18:03:42.728Z,1741284222.728 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-03-06T18:03:42.729Z,1741284222.729 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408A44E0
2025-03-06T18:03:42.730Z,1741284222.730 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1085
2025-03-06T18:03:42.753Z,1741284222.753 [Depth_Keller] Loaded
2025-03-06T18:03:42.753Z,1741284222.753 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-03-06T18:03:42.758Z,1741284222.758 [DropWeight] Loaded
2025-03-06T18:03:42.758Z,1741284222.758 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-03-06T18:03:42.780Z,1741284222.780 [MultiRay] Loaded
2025-03-06T18:03:42.780Z,1741284222.780 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2025-03-06T18:03:42.845Z,1741284222.845 [NAL9602] Loaded
2025-03-06T18:03:42.845Z,1741284222.845 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-03-06T18:03:42.874Z,1741284222.874 [Onboard] Loaded
2025-03-06T18:03:42.875Z,1741284222.875 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-03-06T18:03:42.875Z,1741284222.875 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408D44E0
2025-03-06T18:03:42.876Z,1741284222.876 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1086
2025-03-06T18:03:42.890Z,1741284222.890 [Power24vConverter] Loaded
2025-03-06T18:03:42.890Z,1741284222.890 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-03-06T18:03:42.908Z,1741284222.908 [Radio_Surface] Loaded
2025-03-06T18:03:42.908Z,1741284222.908 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-03-06T18:03:42.909Z,1741284222.909 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409044E0
2025-03-06T18:03:42.910Z,1741284222.910 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1087
2025-03-06T18:03:42.925Z,1741284222.925 [Sonardyne_Nano] Loaded
2025-03-06T18:03:42.925Z,1741284222.925 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-03-06T18:03:42.950Z,1741284222.950 [Waterlinked] Loaded
2025-03-06T18:03:42.950Z,1741284222.950 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2025-03-06T18:03:42.950Z,1741284222.950 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-03-06T18:03:42.951Z,1741284222.951 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-03-06T18:03:43.064Z,1741284223.064 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-03-06T18:03:43.065Z,1741284223.065 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-03-06T18:03:43.078Z,1741284223.078 [NavChart] Loaded
2025-03-06T18:03:43.079Z,1741284223.079 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-03-06T18:03:43.084Z,1741284223.084 [UniversalFixResidualReporter] Loaded
2025-03-06T18:03:43.085Z,1741284223.085 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-03-06T18:03:43.085Z,1741284223.085 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-03-06T18:03:43.086Z,1741284223.086 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-03-06T18:03:43.250Z,1741284223.250 [SBIT](DEBUG): Construct Startup Built In Test.
2025-03-06T18:03:43.264Z,1741284223.264 [SBIT] Loaded
2025-03-06T18:03:43.264Z,1741284223.264 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-03-06T18:03:43.267Z,1741284223.267 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-03-06T18:03:43.280Z,1741284223.280 [IBIT] Loaded
2025-03-06T18:03:43.280Z,1741284223.280 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-03-06T18:03:43.286Z,1741284223.286 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-03-06T18:03:43.365Z,1741284223.365 [CBIT] Loaded
2025-03-06T18:03:43.365Z,1741284223.365 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-03-06T18:03:43.397Z,1741284223.397 [GFScanner] Loaded
2025-03-06T18:03:43.397Z,1741284223.397 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-03-06T18:03:43.398Z,1741284223.398 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-03-06T18:03:43.398Z,1741284223.398 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-03-06T18:03:43.577Z,1741284223.577 [CTD_Seabird] Loaded
2025-03-06T18:03:43.577Z,1741284223.577 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-03-06T18:03:43.578Z,1741284223.578 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0
2025-03-06T18:03:43.579Z,1741284223.579 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1088
2025-03-06T18:03:43.601Z,1741284223.601 [PAR_Licor] Loaded
2025-03-06T18:03:43.602Z,1741284223.602 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-03-06T18:03:43.648Z,1741284223.648 [WetLabsBB2FL] Loaded
2025-03-06T18:03:43.649Z,1741284223.649 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-03-06T18:03:43.650Z,1741284223.650 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A464E0
2025-03-06T18:03:43.650Z,1741284223.650 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1089
2025-03-06T18:03:43.651Z,1741284223.651 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-03-06T18:03:43.651Z,1741284223.651 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-03-06T18:03:43.794Z,1741284223.794 [BuoyancyServo] Loaded
2025-03-06T18:03:43.794Z,1741284223.794 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-03-06T18:03:43.819Z,1741284223.819 [ElevatorServo] Loaded
2025-03-06T18:03:43.819Z,1741284223.819 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-03-06T18:03:43.842Z,1741284223.842 [MassServo] Loaded
2025-03-06T18:03:43.842Z,1741284223.842 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-03-06T18:03:43.865Z,1741284223.865 [RudderServo] Loaded
2025-03-06T18:03:43.866Z,1741284223.866 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-03-06T18:03:43.884Z,1741284223.884 [ThrusterHE] Loaded
2025-03-06T18:03:43.884Z,1741284223.884 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-03-06T18:03:43.885Z,1741284223.885 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-03-06T18:03:43.885Z,1741284223.885 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-03-06T18:03:43.939Z,1741284223.939 [VerticalControl](DEBUG): Construct VerticalControl.
2025-03-06T18:03:43.992Z,1741284223.992 [VerticalControl] Loaded
2025-03-06T18:03:43.992Z,1741284223.992 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-03-06T18:03:43.995Z,1741284223.995 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-03-06T18:03:44.040Z,1741284224.040 [HorizontalControl] Loaded
2025-03-06T18:03:44.040Z,1741284224.040 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-03-06T18:03:44.043Z,1741284224.043 [SpeedControl](DEBUG): Construct SpeedControl.
2025-03-06T18:03:44.044Z,1741284224.044 [SpeedControl] Loaded
2025-03-06T18:03:44.045Z,1741284224.045 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-03-06T18:03:44.048Z,1741284224.048 [LoopControl](DEBUG): Construct LoopControl.
2025-03-06T18:03:44.048Z,1741284224.048 [LoopControl] Loaded
2025-03-06T18:03:44.048Z,1741284224.048 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-03-06T18:03:44.049Z,1741284224.049 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-03-06T18:03:44.049Z,1741284224.049 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-03-06T18:03:44.187Z,1741284224.187 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-03-06T18:03:44.187Z,1741284224.187 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-03-06T18:03:44.371Z,1741284224.371 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-03-06T18:03:44.372Z,1741284224.372 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-03-06T18:03:44.817Z,1741284224.817 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-03-06T18:03:44.818Z,1741284224.818 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-03-06T18:03:44.878Z,1741284224.878 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-03-06T18:03:44.884Z,1741284224.884 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-03-06T18:03:44.887Z,1741284224.887 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-03-06T18:03:44.899Z,1741284224.899 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-03-06T18:03:44.900Z,1741284224.900 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C344E0
2025-03-06T18:03:44.900Z,1741284224.900 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1090
2025-03-06T18:03:44.905Z,1741284224.905 [Supervisor](INFO): Main Thread ID is 830
2025-03-06T18:03:44.905Z,1741284224.905 [Supervisor](DEBUG): Running supervisor.
2025-03-06T18:03:44.906Z,1741284224.906 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1091
2025-03-06T18:03:44.907Z,1741284224.907 [CommandExec](INFO): Initializing the command executive.
2025-03-06T18:03:44.908Z,1741284224.908 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1092
2025-03-06T18:03:44.910Z,1741284224.910 [controlThread ThreadHandler](INFO): Handler Thread ID is 1093
2025-03-06T18:03:44.911Z,1741284224.911 [controlThread](DEBUG): Initializing ControlThread
2025-03-06T18:03:44.912Z,1741284224.912 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-03-06T18:03:44.912Z,1741284224.912 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-03-06T18:03:44.912Z,1741284224.912 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-03-06T18:03:44.913Z,1741284224.913 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-03-06T18:03:44.913Z,1741284224.913 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-03-06T18:03:44.920Z,1741284224.920 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-03-06T18:03:44.921Z,1741284224.921 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-03-06T18:03:44.921Z,1741284224.921 [SBIT](INFO): Initialize SBIT Component.
2025-03-06T18:03:44.921Z,1741284224.921 [SBIT](IMPORTANT): git: 2025-03-06
2025-03-06T18:03:44.922Z,1741284224.922 [SBIT](INFO): git hash: 29d95e23747063b3f10d6be41de220b6d777c7f6
2025-03-06T18:03:44.922Z,1741284224.922 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-03-06T18:03:44.923Z,1741284224.923 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-03-06T18:03:44.924Z,1741284224.924 [SBIT](INFO): Beginning SBIT in 73.000000 seconds.
2025-03-06T18:03:44.925Z,1741284224.925 [IBIT](INFO): Initialize IBIT Component.
2025-03-06T18:03:44.926Z,1741284224.926 [CBIT](DEBUG): Initialize CBIT Component.
2025-03-06T18:03:44.927Z,1741284224.927 [logger ThreadHandler](INFO): Handler Thread ID is 1094
2025-03-06T18:03:44.937Z,1741284224.937 [CBIT](DEBUG): Initialized mux pins.
2025-03-06T18:03:44.937Z,1741284224.937 [CBIT](DEBUG): Initializing the watchdog timer.
2025-03-06T18:03:44.946Z,1741284224.946 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1095
2025-03-06T18:03:44.958Z,1741284224.958 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1096
2025-03-06T18:03:44.960Z,1741284224.960 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-03-06T18:03:44.961Z,1741284224.961 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-03-06T18:03:44.962Z,1741284224.962 [CBIT](DEBUG): Initializing heartbeat.
2025-03-06T18:03:44.970Z,1741284224.970 [Onboard ThreadHandler](INFO): Handler Thread ID is 1097
2025-03-06T18:03:44.987Z,1741284224.987 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1098
2025-03-06T18:03:45.010Z,1741284225.010 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1099
2025-03-06T18:03:45.011Z,1741284225.011 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-03-06T18:03:45.015Z,1741284225.015 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1101
2025-03-06T18:03:45.018Z,1741284225.018 [WetLabsBB2FL](INFO): Powering up
2025-03-06T18:03:45.019Z,1741284225.019 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1103
2025-03-06T18:03:45.022Z,1741284225.022 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-03-06T18:03:45.022Z,1741284225.022 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-03-06T18:03:45.022Z,1741284225.022 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-03-06T18:03:45.022Z,1741284225.022 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-03-06T18:03:45.022Z,1741284225.022 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-03-06T18:03:45.022Z,1741284225.022 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-03-06T18:03:45.023Z,1741284225.023 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-03-06T18:03:45.023Z,1741284225.023 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-03-06T18:03:45.033Z,1741284225.033 [CBIT](DEBUG): Deactivating emergency mode.
2025-03-06T18:03:45.073Z,1741284225.073 [CBIT](DEBUG): Backplane powered.
2025-03-06T18:03:45.074Z,1741284225.074 [GFScanner](DEBUG): Initializing GFScanner
2025-03-06T18:03:45.079Z,1741284225.079 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-03-06T18:03:45.080Z,1741284225.080 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-03-06T18:03:45.081Z,1741284225.081 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-03-06T18:03:45.082Z,1741284225.082 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-03-06T18:03:45.082Z,1741284225.082 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-03-06T18:03:45.083Z,1741284225.083 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-03-06T18:03:45.083Z,1741284225.083 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-03-06T18:03:45.085Z,1741284225.085 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-03-06T18:03:45.133Z,1741284225.133 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="Startup">
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="StartupSatComms">
        <Sequence />
        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix />
        </ReadDatum>
        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications />
        </ReadDatum>
    </Aggregate>
</Mission>

2025-03-06T18:03:45.138Z,1741284225.138 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-06T18:03:45.170Z,1741284225.170 [MissionManager](DEBUG): 
#   Copyright (c) 2024 MBARI
#   MBARI Proprietary Information. Confidential. All Rights Reserved
#   Unauthorized copying or distribution of this file via any medium is strictly
#   prohibited.
#
#   WARNING - This file contains information whose export is restricted by the
#   Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
#   amended. Violations of these export laws are subject to severe civil and/or
#   criminal penalties.

mission Startup {
  behavior Guidance:GoToSurface {
    run in progression
  }

  aggregate StartupSatComms {
    run in sequence

    readDatum {
      timeout duration=P1M

      Universal:latitude_fix
    }

    readDatum {
      timeout duration=P1M

      Universal:platform_communications
    }
  }
}


2025-03-06T18:03:45.171Z,1741284225.171 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-03-06T18:03:45.171Z,1741284225.171 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-03-06T18:03:45.172Z,1741284225.172 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-03-06T18:03:45.394Z,1741284225.394 [Radio_Surface](INFO): Powering up
2025-03-06T18:03:45.403Z,1741284225.403 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="Default">
    <DefineArg Name="ElapsedSinceDefaultStarted">
        <Units:minute />
        <Value>0</Value>
    </DefineArg>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Units:second />
            <Value>13</Value>
        </Setting>
    </Guidance:Wait>
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="CheckIn">
        <Sequence Repeat="288" />
        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M" />
            <Universal:time_fix />
        </ReadDatum>
        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence />
                    <Setting>
                        <Guidance:Execute.command />
                        <String>Burn on</String>
                    </Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications />
        </ReadDatum>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Units:minute />
                <Value>5</Value>
            </Setting>
        </Guidance:Wait>
        <Assign>
            <Sequence />
            <Arg Name="ElapsedSinceDefaultStarted" />
            <Elapsed>
                <Universal:mission_started />
            </Elapsed>
        </Assign>
        <Syslog Severity="Important">
            Default mission has been running for 
            <Arg Name="ElapsedSinceDefaultStarted" />
            <Units:minute />
        </Syslog>
    </Aggregate>
    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>
    <Guidance:Execute>
        <Sequence />
        <Setting>
            <Guidance:Execute.command />
            <String>restart logs</String>
        </Setting>
    </Guidance:Execute>
</Mission>

2025-03-06T18:03:45.426Z,1741284225.426 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-03-06T18:03:45.427Z,1741284225.427 [Default:A.Wait](DEBUG): Construct Wait.
2025-03-06T18:03:45.429Z,1741284225.429 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-06T18:03:45.454Z,1741284225.454 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-06T18:03:45.456Z,1741284225.456 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-06T18:03:45.462Z,1741284225.462 [Default:E.Execute](DEBUG): Construct Execute.
2025-03-06T18:03:45.477Z,1741284225.477 [MissionManager](DEBUG): 
#   Copyright (c) 2024 MBARI
#   MBARI Proprietary Information. Confidential. All Rights Reserved
#   Unauthorized copying or distribution of this file via any medium is strictly
#   prohibited.
#
#   WARNING - This file contains information whose export is restricted by the
#   Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
#   amended. Violations of these export laws are subject to severe civil and/or
#   criminal penalties.

mission Default {
  arguments {
    ElapsedSinceDefaultStarted = 0 minute
  }

  behavior Guidance:Wait {
    """
    Wait a moment to see if the scheduler starts a new mission before
    starting to actually run Default.
    """

    run in sequence

    set duration = 13 second
  }

  behavior Guidance:GoToSurface {
    run in progression
  }

  aggregate CheckIn {
    run in sequence repeat=288

    readDatum id="Read_GPS" {
      timeout duration=P5M

      Universal:time_fix
    }

    readDatum id="Read_Iridium" {
      timeout duration=P4H {
        behavior Guidance:Execute {
          run in sequence

          set command = "Burn on"
        }

        syslog critical "Dropped weight due to communications timeout."
      }

      Universal:platform_communications
    }

    behavior Guidance:Wait {
      run in sequence

      set duration = 5 minute
    }

    assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )

    syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
  }

  syslog important "Restarting logs and Default mission."

  behavior Guidance:Execute {
    run in sequence

    set command = "restart logs"
  }
}


2025-03-06T18:03:45.482Z,1741284225.482 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,Power24vConverter,Sonardyne_Nano,Waterlinked,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-03-06T18:03:45.501Z,1741284225.501 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-03-06T18:03:45.556Z,1741284225.556 [MultiRay](INFO): Powering up MultiRay Lights
2025-03-06T18:03:45.590Z,1741284225.590 [Power24vConverter](INFO): Powering up.
2025-03-06T18:03:45.591Z,1741284225.591 [Sonardyne_Nano](INFO): Initializing.
2025-03-06T18:03:45.659Z,1741284225.659 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-03-06T18:03:45.670Z,1741284225.670 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-03-06T18:03:45.671Z,1741284225.671 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-03-06T18:03:45.678Z,1741284225.678 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-03-06T18:03:45.679Z,1741284225.679 [MassServo](DEBUG): Initializing EZServoServo.
2025-03-06T18:03:45.686Z,1741284225.686 [MassServo](DEBUG): Initializing MassServo.
2025-03-06T18:03:45.686Z,1741284225.686 [RudderServo](DEBUG): Initializing EZServoServo.
2025-03-06T18:03:45.694Z,1741284225.694 [RudderServo](DEBUG): Initializing RudderServo.
2025-03-06T18:03:45.694Z,1741284225.694 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-03-06T18:03:45.702Z,1741284225.702 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-03-06T18:03:47.512Z,1741284227.512 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-03-06T18:03:47.630Z,1741284227.630 [WetLabsBB2FL](INFO): Powering down
2025-03-06T18:03:49.158Z,1741284229.158 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2105
2025-03-06T18:03:51.374Z,1741284231.374 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-03-06T18:03:52.046Z,1741284232.046 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-03-06T18:04:12.971Z,1741284252.971 [NAL9602](INFO): Powering up NAL9602
2025-03-06T18:04:13.780Z,1741284253.780 [Waterlinked](FAULT): Could not initialize.
2025-03-06T18:04:13.780Z,1741284253.780 [Waterlinked] Communications Fault, FailCount= 1
2025-03-06T18:04:13.780Z,1741284253.780 [Waterlinked](ERROR): Communications Fault
2025-03-06T18:04:13.850Z,1741284253.850 [CBIT](ERROR): Communications Fault in component: Waterlinked
2025-03-06T18:04:14.266Z,1741284254.266 [Waterlinked](INFO): Powering down
2025-03-06T18:04:15.054Z,1741284255.054 [CBIT](INFO): Clearing failed state for component Waterlinked
2025-03-06T18:04:15.054Z,1741284255.054 [Waterlinked] No Fault, FailCount= 1
2025-03-06T18:04:23.879Z,1741284263.879 [NAL9602](INFO): NAL9602 initialized
2025-03-06T18:04:25.923Z,1741284265.923 [CommandExec](IMPORTANT): got command strobe off
2025-03-06T18:04:25.923Z,1741284265.923 [CommandExec](IMPORTANT): Deactivating strobe
2025-03-06T18:04:39.994Z,1741284279.994 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent
2025-03-06T18:04:39.995Z,1741284279.995 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 96.000000 %
2025-03-06T18:04:52.694Z,1741284292.694 [Waterlinked](INFO): Powering down
2025-03-06T18:04:58.653Z,1741284298.653 [SBIT](IMPORTANT): Beginning Startup BIT
2025-03-06T18:05:52.100Z,1741284352.100 [SBIT](IMPORTANT): SBIT PASSED
2025-03-06T18:05:52.101Z,1741284352.101 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;

2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;

2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;

2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;

2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;

2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): MultiRay.loadAtStartup=1 bool;

2025-03-06T18:05:52.126Z,1741284352.126 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=185.902950 cubic_centimeter;

2025-03-06T18:05:52.127Z,1741284352.127 [SBIT](IMPORTANT): VerticalControl.massDefault=13.432478 millimeter;

2025-03-06T18:05:52.503Z,1741284352.503 [MissionManager](IMPORTANT): Started mission Startup
2025-03-06T18:05:52.503Z,1741284352.503 [Startup] Running Loop=1
2025-03-06T18:05:52.503Z,1741284352.503 [Startup](DEBUG): Aggregate::initialize Startup
2025-03-06T18:05:52.503Z,1741284352.503 [Startup:A.GoToSurface] Running Loop=1
2025-03-06T18:05:52.503Z,1741284352.503 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T18:05:52.504Z,1741284352.504 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T18:05:52.504Z,1741284352.504 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T18:05:52.504Z,1741284352.504 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T18:05:52.505Z,1741284352.505 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T18:05:52.506Z,1741284352.506 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T18:05:52.506Z,1741284352.506 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T18:05:52.508Z,1741284352.508 [Startup:StartupSatComms] Running Loop=1
2025-03-06T18:05:52.509Z,1741284352.509 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-03-06T18:05:52.509Z,1741284352.509 [Startup:StartupSatComms:A] Running Loop=1
2025-03-06T18:05:52.914Z,1741284352.914 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-03-06T18:06:12.858Z,1741284372.858 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006920
2025-03-06T18:06:45.067Z,1741284405.067 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-03-06T18:06:45.067Z,1741284405.067 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:06:45.090Z,1741284405.090 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:06:45.498Z,1741284405.498 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:06:45.498Z,1741284405.498 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-03-06T18:06:52.748Z,1741284412.748 [Startup:StartupSatComms:A](INFO): Timed out from 2025-03-06T18:05:52.5Z
2025-03-06T18:06:52.748Z,1741284412.748 [Startup:StartupSatComms:A] Stopped
2025-03-06T18:06:52.748Z,1741284412.748 [Startup:StartupSatComms:B] Running Loop=1
2025-03-06T18:06:53.128Z,1741284413.128 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-06T18:06:59.865Z,1741284419.865 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250306T174507/Courier0007.lzma
2025-03-06T18:07:00.867Z,1741284420.867 [DataOverHttps](INFO): Moved sent file to Logs/20250306T174507/Courier0007.lzma.bak
2025-03-06T18:07:00.868Z,1741284420.868 [DataOverHttps](INFO): SBD MOMSN=24134462
2025-03-06T18:07:08.114Z,1741284428.114 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T18:07:15.425Z,1741284435.425 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T18:07:16.409Z,1741284436.409 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250306T180334/Courier0000.lzma
2025-03-06T18:07:17.411Z,1741284437.411 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0000.lzma.bak
2025-03-06T18:07:17.411Z,1741284437.411 [DataOverHttps](INFO): SBD MOMSN=24134469
2025-03-06T18:07:19.423Z,1741284439.423 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T18:07:32.950Z,1741284452.950 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250306T174507/Express0008.lzma
2025-03-06T18:07:34.140Z,1741284454.140 [DataOverHttps](INFO): Moved sent file to Logs/20250306T174507/Express0008.lzma.bak
2025-03-06T18:07:34.140Z,1741284454.140 [DataOverHttps](INFO): SBD MOMSN=24134472
2025-03-06T18:07:49.439Z,1741284469.439 [DataOverHttps](INFO): Sending 854 bytes from file Logs/20250306T180334/Express0001.lzma
2025-03-06T18:07:50.439Z,1741284470.439 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0001.lzma.bak
2025-03-06T18:07:50.439Z,1741284470.439 [DataOverHttps](INFO): SBD MOMSN=24134477
2025-03-06T18:07:51.703Z,1741284471.703 [Startup:StartupSatComms:B] Stopped
2025-03-06T18:07:51.704Z,1741284471.704 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-03-06T18:07:51.704Z,1741284471.704 [Startup:StartupSatComms] Stopped
2025-03-06T18:07:51.704Z,1741284471.704 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-03-06T18:07:51.705Z,1741284471.705 [Startup](INFO): Completed Startup
2025-03-06T18:07:51.705Z,1741284471.705 [MissionManager](INFO): Startup is completed.
2025-03-06T18:07:51.705Z,1741284471.705 [MissionManager](INFO): Uninitializing Mission Startup
2025-03-06T18:07:51.705Z,1741284471.705 [Startup] Stopped
2025-03-06T18:07:51.705Z,1741284471.705 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-03-06T18:07:51.705Z,1741284471.705 [Startup:A.GoToSurface] Stopped
2025-03-06T18:07:51.706Z,1741284471.706 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T18:07:52.110Z,1741284472.110 [MissionManager](IMPORTANT): Started mission Default
2025-03-06T18:07:52.110Z,1741284472.110 [Default] Running Loop=1
2025-03-06T18:07:52.110Z,1741284472.110 [Default](DEBUG): Aggregate::initialize Default
2025-03-06T18:07:52.110Z,1741284472.110 [Default:B.GoToSurface] Running Loop=1
2025-03-06T18:07:52.111Z,1741284472.111 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T18:07:52.111Z,1741284472.111 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T18:07:52.111Z,1741284472.111 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T18:07:52.111Z,1741284472.111 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T18:07:52.112Z,1741284472.112 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T18:07:52.112Z,1741284472.112 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T18:07:52.112Z,1741284472.112 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T18:07:52.113Z,1741284472.113 [Default:A.Wait] Running Loop=1
2025-03-06T18:07:52.113Z,1741284472.113 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:08:05.449Z,1741284485.449 [Default:A.Wait](INFO): Done Waiting.
2025-03-06T18:08:05.449Z,1741284485.449 [Default:A.Wait] Stopped
2025-03-06T18:08:05.450Z,1741284485.450 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T18:08:05.845Z,1741284485.845 [Default:CheckIn] Running Loop=1
2025-03-06T18:08:05.845Z,1741284485.845 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T18:08:05.845Z,1741284485.845 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T18:08:06.248Z,1741284486.248 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-06T18:08:42.253Z,1741284522.253 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T18:09:16.187Z,1741284556.187 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T18:09:27.039Z,1741284567.039 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-06T18:09:46.058Z,1741284586.058 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-03-06T18:09:46.058Z,1741284586.058 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:09:46.116Z,1741284586.116 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:09:46.576Z,1741284586.576 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:09:46.576Z,1741284586.576 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-03-06T18:10:33.938Z,1741284633.938 [CommandExec](IMPORTANT): got command burn on
2025-03-06T18:10:33.939Z,1741284633.939 [CommandExec](IMPORTANT): Activating dropweight wire
2025-03-06T18:10:41.330Z,1741284641.330 [CommandExec](IMPORTANT): got command burn off
2025-03-06T18:10:41.331Z,1741284641.331 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-03-06T18:11:24.771Z,1741284684.771 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T18:11:33.223Z,1741284693.223 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 5.
2025-03-06T18:11:33.231Z,1741284693.231 [BPC1](INFO): Received data from all battery sticks.
2025-03-06T18:12:47.147Z,1741284767.147 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-03-06T18:12:47.147Z,1741284767.147 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:12:47.186Z,1741284767.186 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:12:47.561Z,1741284767.561 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:12:47.561Z,1741284767.561 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-03-06T18:13:06.136Z,1741284786.136 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-06T18:08:05.8Z
2025-03-06T18:13:06.136Z,1741284786.136 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T18:13:06.136Z,1741284786.136 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T18:13:06.560Z,1741284786.560 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-06T18:13:13.285Z,1741284793.285 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250306T180334/Courier0004.lzma
2025-03-06T18:13:14.287Z,1741284794.287 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0004.lzma.bak
2025-03-06T18:13:14.287Z,1741284794.287 [DataOverHttps](INFO): SBD MOMSN=24134510
2025-03-06T18:13:29.714Z,1741284809.714 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20250306T180334/Express0005.lzma
2025-03-06T18:13:30.715Z,1741284810.715 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0005.lzma.bak
2025-03-06T18:13:30.715Z,1741284810.715 [DataOverHttps](INFO): SBD MOMSN=24134516
2025-03-06T18:13:31.991Z,1741284811.991 [Default:CheckIn:Read_Iridium] Stopped
2025-03-06T18:13:31.992Z,1741284811.992 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-06T18:13:31.992Z,1741284811.992 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:14:15.213Z,1741284855.213 [Power24vConverter](INFO): Powering down.
2025-03-06T18:14:25.306Z,1741284865.306 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-06T18:14:25.306Z,1741284865.306 [NAL9602] Data Fault, FailCount= 1
2025-03-06T18:14:25.306Z,1741284865.306 [NAL9602](ERROR): Data Fault
2025-03-06T18:14:25.352Z,1741284865.352 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-06T18:14:25.727Z,1741284865.727 [NAL9602](INFO): Powering down
2025-03-06T18:14:26.544Z,1741284866.544 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-06T18:14:26.544Z,1741284866.544 [NAL9602] No Fault, FailCount= 1
2025-03-06T18:14:56.015Z,1741284896.015 [NAL9602](INFO): Powering up NAL9602
2025-03-06T18:15:06.927Z,1741284906.927 [NAL9602](INFO): NAL9602 initialized
2025-03-06T18:15:48.146Z,1741284948.146 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-03-06T18:15:48.146Z,1741284948.146 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:15:48.157Z,1741284948.157 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:15:48.571Z,1741284948.571 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:15:48.571Z,1741284948.571 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-03-06T18:18:32.568Z,1741285112.568 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-06T18:18:32.568Z,1741285112.568 [Default:CheckIn:C.Wait] Stopped
2025-03-06T18:18:32.568Z,1741285112.568 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T18:18:32.568Z,1741285112.568 [Default:CheckIn:D] Running Loop=1
2025-03-06T18:18:32.971Z,1741285112.971 [Default:CheckIn:D] Stopped
2025-03-06T18:18:32.972Z,1741285112.972 [Default:CheckIn:E] Running Loop=1
2025-03-06T18:18:33.396Z,1741285113.396 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  10.681019 min 
2025-03-06T18:18:33.396Z,1741285113.396 [Default:CheckIn:E] Stopped
2025-03-06T18:18:33.396Z,1741285113.396 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-06T18:18:33.396Z,1741285113.396 [Default:CheckIn] Stopped
2025-03-06T18:18:33.396Z,1741285113.396 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T18:18:33.396Z,1741285113.396 [Default:CheckIn](INFO): Running loop #2
2025-03-06T18:18:33.397Z,1741285113.397 [Default:CheckIn] Running Loop=2
2025-03-06T18:18:33.397Z,1741285113.397 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T18:18:33.397Z,1741285113.397 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T18:18:49.163Z,1741285129.163 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-03-06T18:18:49.163Z,1741285129.163 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:18:49.173Z,1741285129.173 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:18:49.547Z,1741285129.547 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:18:49.547Z,1741285129.547 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-03-06T18:21:50.181Z,1741285310.181 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-03-06T18:21:50.181Z,1741285310.181 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:21:50.228Z,1741285310.228 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:21:50.588Z,1741285310.588 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:21:50.588Z,1741285310.588 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-03-06T18:23:25.905Z,1741285405.905 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T18:23:25.905Z,1741285405.905 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T18:23:25.905Z,1741285405.905 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T18:23:25.906Z,1741285405.906 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T18:23:26.198Z,1741285406.198 [MissionManager](DEBUG): TethyslAPI: ./Missions/Maintenance/run_backseat_on_surface.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="run_backseat_on_surface">
    <DefineArg Name="ElapsedSinceMissionStarted">
        <Units:minute />
        <Value>0</Value>
    </DefineArg>
    <Insert Filename="Insert/BackseatDriver.tl" />
    <Assign>
        <Sequence />
        <Arg Name="BackseatDriver:EnableBackseat" />
        <True />
    </Assign>
    <Insert Filename="Insert/PowerOnly.tl" />
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="CheckIn">
        <Sequence Repeat="288" />
        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M" />
            <Universal:time_fix />
        </ReadDatum>
        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence />
                    <Setting>
                        <Guidance:Execute.command />
                        <String>Burn on</String>
                    </Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications />
        </ReadDatum>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Units:minute />
                <Value>5</Value>
            </Setting>
        </Guidance:Wait>
        <Assign>
            <Sequence />
            <Arg Name="ElapsedSinceMissionStarted" />
            <Elapsed>
                <Universal:mission_started />
            </Elapsed>
        </Assign>
        <Syslog Severity="Important">
            run_backseat_on_surface mission has been running for 
            <Arg Name="ElapsedSinceMissionStarted" />
            <Units:minute />
        </Syslog>
    </Aggregate>
    <Syslog Severity="Important">Restarting logs and run_backseat_on_surface mission.</Syslog>
    <Guidance:Execute>
        <Sequence />
        <Setting>
            <Guidance:Execute.command />
            <String>restart logs</String>
        </Setting>
    </Guidance:Execute>
</Mission>

2025-03-06T18:23:26.203Z,1741285406.203 [MissionManager](INFO): DefineArg run_backseat_on_surface.ElapsedSinceMissionStarted = 0.000000 min
2025-03-06T18:23:26.203Z,1741285406.203 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-03-06T18:23:26.203Z,1741285406.203 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-03-06T18:23:26.204Z,1741285406.204 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-03-06T18:23:26.249Z,1741285406.249 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Aggregate Id="BackseatDriver">
    <DefineArg Name="EnableBackseat">
        <False />
    </DefineArg>
    <Parallel />
    <Guidance:BackseatDriver>
        <Sequence />
        <Setting>
            <Guidance:BackseatDriver.powerBackseat />
            <Arg Name="EnableBackseat" />
        </Setting>
    </Guidance:BackseatDriver>
</Aggregate>

2025-03-06T18:23:26.253Z,1741285406.253 [MissionManager](INFO): DefineArg run_backseat_on_surface:BackseatDriver.EnableBackseat = 0 bool
2025-03-06T18:23:26.256Z,1741285406.256 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-03-06T18:23:26.260Z,1741285406.260 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2025-03-06T18:23:26.260Z,1741285406.260 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2025-03-06T18:23:26.318Z,1741285406.318 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2025-03-06T18:23:26.451Z,1741285406.451 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Aggregate Id="PowerOnly">
    <DefineArg Name="SampleAll">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad1">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad2">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad3">
        <False />
    </DefineArg>
    <DefineArg Name="EnabledPowerOnly">
        <Sensor:PowerOnly.loadAtStartup />
    </DefineArg>
    <Parallel />
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleAll" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.samplePowerOnly />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad1" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad1 />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad2" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad2 />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad3" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad3 />
    </ReadData>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Units:hour />
            <Value>99999</Value>
        </Setting>
    </Guidance:Wait>
</Aggregate>

2025-03-06T18:23:26.456Z,1741285406.456 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleAll = 0 bool
2025-03-06T18:23:26.459Z,1741285406.459 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad1 = 0 bool
2025-03-06T18:23:26.462Z,1741285406.462 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad2 = 0 bool
2025-03-06T18:23:26.465Z,1741285406.465 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad3 = 0 bool
2025-03-06T18:23:26.468Z,1741285406.468 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.EnabledPowerOnly = 0 bool
2025-03-06T18:23:26.508Z,1741285406.508 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Construct Wait.
2025-03-06T18:23:26.514Z,1741285406.514 [run_backseat_on_surface:D.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-06T18:23:26.549Z,1741285406.549 [run_backseat_on_surface:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-06T18:23:26.563Z,1741285406.563 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-06T18:23:26.578Z,1741285406.578 [run_backseat_on_surface:G.Execute](DEBUG): Construct Execute.
2025-03-06T18:23:26.587Z,1741285406.587 [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 run_backseat_on_surface {
  arguments {
    ElapsedSinceMissionStarted = 0 minute
  }

  # Power the science payload.

#  insert id="Science" Insert/Science.tl

  # Power the Backseat payload.

  insert Insert/BackseatDriver.tl

  assign in sequence BackseatDriver:EnableBackseat = true

  insert Insert/PowerOnly.tl

  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=P2H {
        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 ElapsedSinceMissionStarted = elapsed ( Universal:mission_started )

    syslog important "run_backseat_on_surface mission has been running for "
         + ElapsedSinceMissionStarted~minute
  }

  syslog important "Restarting logs and run_backseat_on_surface mission."

  behavior Guidance:Execute {
    run in sequence

    set command = "restart logs"
  }
}


2025-03-06T18:23:26.593Z,1741285406.593 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T18:23:26.736Z,1741285406.736 [Default] Stopped
2025-03-06T18:23:26.736Z,1741285406.736 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-06T18:23:26.736Z,1741285406.736 [Default:B.GoToSurface] Stopped
2025-03-06T18:23:26.736Z,1741285406.736 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T18:23:26.736Z,1741285406.736 [Default:CheckIn] Stopped
2025-03-06T18:23:26.736Z,1741285406.736 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T18:23:26.737Z,1741285406.737 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T18:23:26.737Z,1741285406.737 [MissionManager](IMPORTANT): Started mission run_backseat_on_surface
2025-03-06T18:23:26.737Z,1741285406.737 [run_backseat_on_surface] Running Loop=1
2025-03-06T18:23:26.737Z,1741285406.737 [run_backseat_on_surface](DEBUG): Aggregate::initialize run_backseat_on_surface
2025-03-06T18:23:26.761Z,1741285406.761 [run_backseat_on_surface:BackseatDriver] Running Loop=1
2025-03-06T18:23:26.761Z,1741285406.761 [run_backseat_on_surface:BackseatDriver](DEBUG): Aggregate::initialize run_backseat_on_surface:BackseatDriver
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly](DEBUG): Aggregate::initialize run_backseat_on_surface:PowerOnly
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly:A] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly:B] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly:C] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly:D] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly:E.Wait] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:D.GoToSurface] Running Loop=1
2025-03-06T18:23:26.762Z,1741285406.762 [run_backseat_on_surface:D.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T18:23:26.763Z,1741285406.763 [run_backseat_on_surface:D.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T18:23:26.763Z,1741285406.763 [run_backseat_on_surface:D.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T18:23:26.764Z,1741285406.764 [run_backseat_on_surface:D.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T18:23:26.764Z,1741285406.764 [run_backseat_on_surface:D.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T18:23:26.764Z,1741285406.764 [run_backseat_on_surface:D.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T18:23:26.765Z,1741285406.765 [run_backseat_on_surface:D.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T18:23:26.765Z,1741285406.765 [run_backseat_on_surface:B] Running Loop=1
2025-03-06T18:23:26.770Z,1741285406.770 [run_backseat_on_surface:PowerOnly] Running Loop=1
2025-03-06T18:23:26.770Z,1741285406.770 [run_backseat_on_surface:PowerOnly:D] Stopped
2025-03-06T18:23:26.771Z,1741285406.771 [run_backseat_on_surface:PowerOnly:C] Stopped
2025-03-06T18:23:26.771Z,1741285406.771 [run_backseat_on_surface:PowerOnly:B] Stopped
2025-03-06T18:23:26.771Z,1741285406.771 [run_backseat_on_surface:PowerOnly:A] Stopped
2025-03-06T18:23:26.771Z,1741285406.771 [run_backseat_on_surface:B] Stopped
2025-03-06T18:23:26.771Z,1741285406.771 [run_backseat_on_surface:BackseatDriver] Running Loop=1
2025-03-06T18:23:26.772Z,1741285406.772 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-03-06T18:23:26.802Z,1741285406.802 [BackseatComponent](INFO): Powering up
2025-03-06T18:23:26.802Z,1741285406.802 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T18:23:27.117Z,1741285407.117 [Power24vConverter](INFO): Powering up.
2025-03-06T18:23:27.128Z,1741285407.128 [run_backseat_on_surface:CheckIn] Running Loop=1
2025-03-06T18:23:27.128Z,1741285407.128 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2025-03-06T18:23:27.128Z,1741285407.128 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2025-03-06T18:23:27.552Z,1741285407.552 [run_backseat_on_surface:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-06T18:24:51.159Z,1741285491.159 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-03-06T18:24:51.159Z,1741285491.159 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:24:51.198Z,1741285491.198 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:24:51.602Z,1741285491.602 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:24:51.602Z,1741285491.602 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-03-06T18:25:09.331Z,1741285509.331 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-06T18:25:09.331Z,1741285509.331 [NAL9602] Data Fault, FailCount= 2
2025-03-06T18:25:09.331Z,1741285509.331 [NAL9602](ERROR): Data Fault
2025-03-06T18:25:09.350Z,1741285509.350 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-06T18:25:09.735Z,1741285509.735 [NAL9602](INFO): Powering down
2025-03-06T18:25:10.581Z,1741285510.581 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-06T18:25:10.581Z,1741285510.581 [NAL9602] No Fault, FailCount= 2
2025-03-06T18:25:40.035Z,1741285540.035 [NAL9602](INFO): Powering up NAL9602
2025-03-06T18:25:50.943Z,1741285550.943 [NAL9602](INFO): NAL9602 initialized
2025-03-06T18:27:52.164Z,1741285672.164 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-03-06T18:27:52.164Z,1741285672.164 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:27:52.206Z,1741285672.206 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:27:52.570Z,1741285672.570 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:27:52.570Z,1741285672.570 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-03-06T18:28:27.304Z,1741285707.304 [run_backseat_on_surface:CheckIn:Read_GPS](INFO): Timed out from 2025-03-06T18:23:27.1Z
2025-03-06T18:28:27.304Z,1741285707.304 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2025-03-06T18:28:27.304Z,1741285707.304 [run_backseat_on_surface:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T18:28:27.714Z,1741285707.714 [run_backseat_on_surface:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-06T18:28:34.217Z,1741285714.217 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250306T180334/Courier0007.lzma
2025-03-06T18:28:35.219Z,1741285715.219 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0007.lzma.bak
2025-03-06T18:28:35.219Z,1741285715.219 [DataOverHttps](INFO): SBD MOMSN=24134616
2025-03-06T18:28:45.181Z,1741285725.181 [BackseatComponent](FAULT): Failed to receive device response within the specified timeout.
2025-03-06T18:28:45.181Z,1741285725.181 [BackseatComponent] Communications Fault, FailCount= 1
2025-03-06T18:28:45.181Z,1741285725.181 [BackseatComponent](ERROR): Communications Fault
2025-03-06T18:28:45.182Z,1741285725.182 [Power24vConverter] Hardware Fault, FailCount= 1
2025-03-06T18:28:45.182Z,1741285725.182 [Power24vConverter](ERROR): Hardware Fault
2025-03-06T18:28:45.468Z,1741285725.468 [Power24vConverter](INFO): Powering down.
2025-03-06T18:28:45.518Z,1741285725.518 [CBIT](ERROR): Communications Fault in component: BackseatComponent
2025-03-06T18:28:45.518Z,1741285725.518 [CBIT](ERROR): Hardware Fault in component: Power24vConverter
2025-03-06T18:28:45.593Z,1741285725.593 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T18:28:45.594Z,1741285725.594 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T18:28:46.290Z,1741285726.290 [Power24vConverter](INFO): Powering up.
2025-03-06T18:28:46.335Z,1741285726.335 [CBIT](INFO): Clearing failed state for component Power24vConverter
2025-03-06T18:28:46.335Z,1741285726.335 [Power24vConverter] No Fault, FailCount= 1
2025-03-06T18:28:50.786Z,1741285730.786 [DataOverHttps](INFO): Sending 277 bytes from file Logs/20250306T180334/Express0008.lzma
2025-03-06T18:28:51.787Z,1741285731.787 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0008.lzma.bak
2025-03-06T18:28:51.787Z,1741285731.787 [DataOverHttps](INFO): SBD MOMSN=24134618
2025-03-06T18:28:53.169Z,1741285733.169 [run_backseat_on_surface:CheckIn:Read_Iridium] Stopped
2025-03-06T18:28:53.169Z,1741285733.169 [run_backseat_on_surface:CheckIn:C.Wait] Running Loop=1
2025-03-06T18:28:53.169Z,1741285733.169 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:29:03.774Z,1741285743.774 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T18:29:03.774Z,1741285743.774 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T18:29:03.775Z,1741285743.775 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T18:29:22.358Z,1741285762.358 [BackseatComponent](INFO): Powering up
2025-03-06T18:29:22.358Z,1741285762.358 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T18:29:22.662Z,1741285762.662 [CBIT](INFO): Clearing failed state for component BackseatComponent
2025-03-06T18:29:22.662Z,1741285762.662 [BackseatComponent] No Fault, FailCount= 1
2025-03-06T18:30:53.159Z,1741285853.159 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-03-06T18:30:53.159Z,1741285853.159 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:30:53.174Z,1741285853.174 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:30:53.566Z,1741285853.566 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:30:53.566Z,1741285853.566 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-03-06T18:33:53.767Z,1741286033.767 [run_backseat_on_surface:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-06T18:33:53.767Z,1741286033.767 [run_backseat_on_surface:CheckIn:C.Wait] Stopped
2025-03-06T18:33:53.767Z,1741286033.767 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T18:33:53.768Z,1741286033.768 [run_backseat_on_surface:CheckIn:D] Running Loop=1
2025-03-06T18:33:54.171Z,1741286034.171 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2025-03-06T18:33:54.171Z,1741286034.171 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:33:54.172Z,1741286034.172 [run_backseat_on_surface:CheckIn:D] Stopped
2025-03-06T18:33:54.172Z,1741286034.172 [run_backseat_on_surface:CheckIn:E] Running Loop=1
2025-03-06T18:33:54.186Z,1741286034.186 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:33:54.585Z,1741286034.585 [run_backseat_on_surface:CheckIn:E](IMPORTANT): run_backseat_on_surface mission has been running for  10.457252 min 
2025-03-06T18:33:54.585Z,1741286034.585 [run_backseat_on_surface:CheckIn:E] Stopped
2025-03-06T18:33:54.585Z,1741286034.585 [run_backseat_on_surface:CheckIn](INFO): Completed run_backseat_on_surface:CheckIn
2025-03-06T18:33:54.585Z,1741286034.585 [run_backseat_on_surface:CheckIn] Stopped
2025-03-06T18:33:54.585Z,1741286034.585 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2025-03-06T18:33:54.585Z,1741286034.585 [run_backseat_on_surface:CheckIn](INFO): Running loop #2
2025-03-06T18:33:54.585Z,1741286034.585 [run_backseat_on_surface:CheckIn] Running Loop=2
2025-03-06T18:33:54.586Z,1741286034.586 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2025-03-06T18:33:54.586Z,1741286034.586 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2025-03-06T18:33:54.597Z,1741286034.597 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:33:54.598Z,1741286034.598 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2025-03-06T18:34:40.737Z,1741286080.737 [BackseatComponent](FAULT): Failed to receive device response within the specified timeout.
2025-03-06T18:34:40.737Z,1741286080.737 [BackseatComponent] Communications Fault, FailCount= 2
2025-03-06T18:34:40.737Z,1741286080.737 [BackseatComponent](ERROR): Communications Fault
2025-03-06T18:34:40.738Z,1741286080.738 [Power24vConverter] Hardware Fault, FailCount= 1
2025-03-06T18:34:40.738Z,1741286080.738 [Power24vConverter](ERROR): Hardware Fault
2025-03-06T18:34:41.038Z,1741286081.038 [Power24vConverter](INFO): Powering down.
2025-03-06T18:34:41.062Z,1741286081.062 [CBIT](ERROR): Communications Fault in component: BackseatComponent
2025-03-06T18:34:41.063Z,1741286081.063 [CBIT](ERROR): Hardware Fault in component: Power24vConverter
2025-03-06T18:34:41.143Z,1741286081.143 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T18:34:41.144Z,1741286081.144 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T18:34:41.831Z,1741286081.831 [Power24vConverter](INFO): Powering up.
2025-03-06T18:34:41.853Z,1741286081.853 [CBIT](INFO): Clearing failed state for component Power24vConverter
2025-03-06T18:34:41.854Z,1741286081.854 [Power24vConverter] No Fault, FailCount= 1
2025-03-06T18:34:59.326Z,1741286099.326 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T18:34:59.326Z,1741286099.326 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T18:34:59.327Z,1741286099.327 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T18:35:17.910Z,1741286117.910 [BackseatComponent](INFO): Powering up
2025-03-06T18:35:17.910Z,1741286117.910 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T18:35:18.251Z,1741286118.251 [CBIT](INFO): Clearing failed state for component BackseatComponent
2025-03-06T18:35:18.251Z,1741286118.251 [BackseatComponent] No Fault, FailCount= 2
2025-03-06T18:35:54.556Z,1741286154.556 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-06T18:35:54.556Z,1741286154.556 [NAL9602] Data Fault, FailCount= 3
2025-03-06T18:35:54.556Z,1741286154.556 [NAL9602](ERROR): Data Fault
2025-03-06T18:35:54.578Z,1741286154.578 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-06T18:35:54.955Z,1741286154.955 [NAL9602](INFO): Powering down
2025-03-06T18:35:55.781Z,1741286155.781 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-06T18:35:55.782Z,1741286155.782 [NAL9602] No Fault, FailCount= 3
2025-03-06T18:36:25.259Z,1741286185.259 [NAL9602](INFO): Powering up NAL9602
2025-03-06T18:36:36.163Z,1741286196.163 [NAL9602](INFO): NAL9602 initialized
2025-03-06T18:36:55.177Z,1741286215.177 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2025-03-06T18:36:55.177Z,1741286215.177 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:36:55.190Z,1741286215.190 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:36:55.590Z,1741286215.590 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:36:55.590Z,1741286215.590 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2025-03-06T18:38:54.756Z,1741286334.756 [run_backseat_on_surface:CheckIn:Read_GPS](INFO): Timed out from 2025-03-06T18:33:54.6Z
2025-03-06T18:38:54.756Z,1741286334.756 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2025-03-06T18:38:54.757Z,1741286334.757 [run_backseat_on_surface:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T18:39:00.337Z,1741286340.337 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250306T180334/Courier0010.lzma
2025-03-06T18:39:01.339Z,1741286341.339 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0010.lzma.bak
2025-03-06T18:39:01.339Z,1741286341.339 [DataOverHttps](INFO): SBD MOMSN=24134700
2025-03-06T18:39:16.938Z,1741286356.938 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20250306T180334/Express0011.lzma
2025-03-06T18:39:17.941Z,1741286357.941 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0011.lzma.bak
2025-03-06T18:39:17.941Z,1741286357.941 [DataOverHttps](INFO): SBD MOMSN=24134705
2025-03-06T18:39:19.008Z,1741286359.008 [run_backseat_on_surface:CheckIn:Read_Iridium] Stopped
2025-03-06T18:39:19.008Z,1741286359.008 [run_backseat_on_surface:CheckIn:C.Wait] Running Loop=1
2025-03-06T18:39:19.008Z,1741286359.008 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:39:56.178Z,1741286396.178 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2025-03-06T18:39:56.178Z,1741286396.178 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:39:56.190Z,1741286396.190 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:39:56.578Z,1741286396.578 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:39:56.578Z,1741286396.578 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2025-03-06T18:40:36.277Z,1741286436.277 [BackseatComponent](FAULT): Failed to receive device response within the specified timeout.
2025-03-06T18:40:36.277Z,1741286436.277 [BackseatComponent] Communications Fault, FailCount= 3
2025-03-06T18:40:36.277Z,1741286436.277 [BackseatComponent](ERROR): Communications Fault
2025-03-06T18:40:36.278Z,1741286436.278 [Power24vConverter] Hardware Fault, FailCount= 1
2025-03-06T18:40:36.278Z,1741286436.278 [Power24vConverter](ERROR): Hardware Fault
2025-03-06T18:40:36.562Z,1741286436.562 [Power24vConverter](INFO): Powering down.
2025-03-06T18:40:36.586Z,1741286436.586 [CBIT](ERROR): Communications Fault in component: BackseatComponent
2025-03-06T18:40:36.586Z,1741286436.586 [CBIT](ERROR): Hardware Fault in component: Power24vConverter
2025-03-06T18:40:36.683Z,1741286436.683 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T18:40:36.683Z,1741286436.683 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T18:40:37.356Z,1741286437.356 [Power24vConverter](INFO): Powering up.
2025-03-06T18:40:37.398Z,1741286437.398 [CBIT](INFO): Clearing failed state for component Power24vConverter
2025-03-06T18:40:37.398Z,1741286437.398 [Power24vConverter] No Fault, FailCount= 1
2025-03-06T18:40:54.862Z,1741286454.862 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T18:40:54.862Z,1741286454.862 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T18:40:54.863Z,1741286454.863 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T18:41:13.446Z,1741286473.446 [BackseatComponent](INFO): Powering up
2025-03-06T18:41:13.446Z,1741286473.446 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T18:41:13.758Z,1741286473.758 [CBIT](INFO): Clearing failed state for component BackseatComponent
2025-03-06T18:41:13.758Z,1741286473.758 [BackseatComponent] No Fault, FailCount= 3
2025-03-06T18:42:57.148Z,1741286577.148 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2025-03-06T18:42:57.148Z,1741286577.148 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:42:57.162Z,1741286577.162 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:42:57.582Z,1741286577.582 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:42:57.582Z,1741286577.582 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2025-03-06T18:44:19.564Z,1741286659.564 [run_backseat_on_surface:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-06T18:44:19.564Z,1741286659.564 [run_backseat_on_surface:CheckIn:C.Wait] Stopped
2025-03-06T18:44:19.564Z,1741286659.564 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T18:44:19.564Z,1741286659.564 [run_backseat_on_surface:CheckIn:D] Running Loop=1
2025-03-06T18:44:19.968Z,1741286659.968 [run_backseat_on_surface:CheckIn:D] Stopped
2025-03-06T18:44:19.968Z,1741286659.968 [run_backseat_on_surface:CheckIn:E] Running Loop=1
2025-03-06T18:44:20.373Z,1741286660.373 [run_backseat_on_surface:CheckIn:E](IMPORTANT): run_backseat_on_surface mission has been running for  20.887179 min 
2025-03-06T18:44:20.373Z,1741286660.373 [run_backseat_on_surface:CheckIn:E] Stopped
2025-03-06T18:44:20.373Z,1741286660.373 [run_backseat_on_surface:CheckIn](INFO): Completed run_backseat_on_surface:CheckIn
2025-03-06T18:44:20.373Z,1741286660.373 [run_backseat_on_surface:CheckIn] Stopped
2025-03-06T18:44:20.373Z,1741286660.373 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2025-03-06T18:44:20.373Z,1741286660.373 [run_backseat_on_surface:CheckIn](INFO): Running loop #3
2025-03-06T18:44:20.374Z,1741286660.374 [run_backseat_on_surface:CheckIn] Running Loop=3
2025-03-06T18:44:20.374Z,1741286660.374 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2025-03-06T18:44:20.374Z,1741286660.374 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2025-03-06T18:45:58.156Z,1741286758.156 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2025-03-06T18:45:58.156Z,1741286758.156 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:45:58.170Z,1741286758.170 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:45:58.566Z,1741286758.566 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:45:58.566Z,1741286758.566 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2025-03-06T18:46:31.809Z,1741286791.809 [BackseatComponent](FAULT): Failed to receive device response within the specified timeout.
2025-03-06T18:46:31.809Z,1741286791.809 [BackseatComponent] Communications Fault, FailCount= 4
2025-03-06T18:46:31.809Z,1741286791.809 [BackseatComponent](ERROR): Communications Fault
2025-03-06T18:46:31.810Z,1741286791.810 [Power24vConverter] Hardware Fault, FailCount= 1
2025-03-06T18:46:31.810Z,1741286791.810 [Power24vConverter](ERROR): Hardware Fault
2025-03-06T18:46:32.092Z,1741286792.092 [Power24vConverter](INFO): Powering down.
2025-03-06T18:46:32.130Z,1741286792.130 [CBIT](ERROR): Communications Fault in component: BackseatComponent
2025-03-06T18:46:32.130Z,1741286792.130 [CBIT](ERROR): Hardware Fault in component: Power24vConverter
2025-03-06T18:46:32.214Z,1741286792.214 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T18:46:32.215Z,1741286792.215 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T18:46:32.878Z,1741286792.878 [Power24vConverter](INFO): Powering up.
2025-03-06T18:46:32.898Z,1741286792.898 [CBIT](INFO): Clearing failed state for component Power24vConverter
2025-03-06T18:46:32.898Z,1741286792.898 [Power24vConverter] No Fault, FailCount= 1
2025-03-06T18:46:39.339Z,1741286799.339 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-06T18:46:39.339Z,1741286799.339 [NAL9602] Data Fault, FailCount= 4
2025-03-06T18:46:39.339Z,1741286799.339 [NAL9602](ERROR): Data Fault
2025-03-06T18:46:39.358Z,1741286799.358 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-06T18:46:39.739Z,1741286799.739 [NAL9602](INFO): Powering down
2025-03-06T18:46:40.570Z,1741286800.570 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-06T18:46:40.570Z,1741286800.570 [NAL9602] No Fault, FailCount= 4
2025-03-06T18:46:50.394Z,1741286810.394 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T18:46:50.394Z,1741286810.394 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T18:46:50.395Z,1741286810.395 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T18:47:08.978Z,1741286828.978 [BackseatComponent](INFO): Powering up
2025-03-06T18:47:08.978Z,1741286828.978 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T18:47:09.254Z,1741286829.254 [CBIT](INFO): Clearing failed state for component BackseatComponent
2025-03-06T18:47:09.254Z,1741286829.254 [BackseatComponent] No Fault, FailCount= 4
2025-03-06T18:47:10.039Z,1741286830.039 [NAL9602](INFO): Powering up NAL9602
2025-03-06T18:47:20.948Z,1741286840.948 [NAL9602](INFO): NAL9602 initialized
2025-03-06T18:48:59.163Z,1741286939.163 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2025-03-06T18:48:59.163Z,1741286939.163 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:48:59.178Z,1741286939.178 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:48:59.546Z,1741286939.546 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:48:59.546Z,1741286939.546 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2025-03-06T18:49:20.544Z,1741286960.544 [run_backseat_on_surface:CheckIn:Read_GPS](INFO): Timed out from 2025-03-06T18:44:20.4Z
2025-03-06T18:49:20.544Z,1741286960.544 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2025-03-06T18:49:20.544Z,1741286960.544 [run_backseat_on_surface:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T18:49:26.369Z,1741286966.369 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250306T180334/Courier0013.lzma
2025-03-06T18:49:27.371Z,1741286967.371 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0013.lzma.bak
2025-03-06T18:49:27.371Z,1741286967.371 [DataOverHttps](INFO): SBD MOMSN=24134725
2025-03-06T18:49:42.854Z,1741286982.854 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20250306T180334/Express0014.lzma
2025-03-06T18:49:43.855Z,1741286983.855 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0014.lzma.bak
2025-03-06T18:49:43.855Z,1741286983.855 [DataOverHttps](INFO): SBD MOMSN=24134733
2025-03-06T18:49:45.191Z,1741286985.191 [run_backseat_on_surface:CheckIn:Read_Iridium] Stopped
2025-03-06T18:49:45.191Z,1741286985.191 [run_backseat_on_surface:CheckIn:C.Wait] Running Loop=1
2025-03-06T18:49:45.191Z,1741286985.191 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:51:08.663Z,1741287068.663 [CommandExec](IMPORTANT): got command show variable backseatcompoennt
2025-03-06T18:51:14.340Z,1741287074.340 [CommandExec](IMPORTANT): got command show variable backseatcomponenmt
2025-03-06T18:51:15.576Z,1741287075.576 [CommandExec](IMPORTANT): got command show variable backseatcomponent
2025-03-06T18:51:15.586Z,1741287075.586 [CommandExec](IMPORTANT): BackseatComponent.loadControl (none)
2025-03-06T18:51:15.586Z,1741287075.586 [CommandExec](IMPORTANT): BackseatComponent.loadControl2 (none)
2025-03-06T18:51:15.587Z,1741287075.587 [CommandExec](IMPORTANT): BackseatComponent.uart (none)
2025-03-06T18:51:15.587Z,1741287075.587 [CommandExec](IMPORTANT): BackseatComponent.baud (bit_per_second)
2025-03-06T18:51:15.822Z,1741287075.822 [CommandExec](IMPORTANT): BackseatComponent.loadAtStartup (bool)
2025-03-06T18:51:15.822Z,1741287075.822 [CommandExec](IMPORTANT): BackseatComponent.simulateHardware (bool)
2025-03-06T18:51:15.823Z,1741287075.823 [CommandExec](IMPORTANT): BackseatComponent.shutdownCmd (none)
2025-03-06T18:51:15.823Z,1741287075.823 [CommandExec](IMPORTANT): BackseatComponent.lcmListenerTimeout (second)
2025-03-06T18:51:15.824Z,1741287075.824 [CommandExec](IMPORTANT): BackseatComponent.verbosity (count)
2025-03-06T18:51:15.824Z,1741287075.824 [CommandExec](IMPORTANT): BackseatComponent.alwaysOn (bool)
2025-03-06T18:51:15.824Z,1741287075.824 [CommandExec](IMPORTANT): BackseatComponent.needs24v (bool)
2025-03-06T18:51:15.825Z,1741287075.825 [CommandExec](IMPORTANT): BackseatComponent.poTimeout (second)
2025-03-06T18:51:15.826Z,1741287075.826 [CommandExec](IMPORTANT): BackseatComponent.missionCritical (bool)
2025-03-06T18:51:15.906Z,1741287075.906 [CommandExec](IMPORTANT): BackseatComponent.enableBroadcast (bool)
2025-03-06T18:51:15.907Z,1741287075.907 [CommandExec](IMPORTANT): BackseatComponent.component_voltage (volt)
2025-03-06T18:51:15.907Z,1741287075.907 [CommandExec](IMPORTANT): BackseatComponent.component_avgVoltage (volt)
2025-03-06T18:51:15.907Z,1741287075.907 [CommandExec](IMPORTANT): BackseatComponent.component_current (milliampere)
2025-03-06T18:51:15.908Z,1741287075.908 [CommandExec](IMPORTANT): BackseatComponent.component_avgCurrent (milliampere)
2025-03-06T18:51:15.908Z,1741287075.908 [CommandExec](IMPORTANT): BackseatComponent.component_discreteIn (bool)
2025-03-06T18:51:15.909Z,1741287075.909 [CommandExec](IMPORTANT): BackseatComponent.handled_message (bool)
2025-03-06T18:51:15.909Z,1741287075.909 [CommandExec](IMPORTANT): BackseatComponent.power_backseat (bool)
2025-03-06T18:51:27.414Z,1741287087.414 [CommandExec](IMPORTANT): got command report mod BackseatComponent.handled_message
2025-03-06T18:51:27.461Z,1741287087.461 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T18:52:00.146Z,1741287120.146 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2025-03-06T18:52:00.147Z,1741287120.147 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:52:00.162Z,1741287120.162 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:52:00.586Z,1741287120.586 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:52:00.586Z,1741287120.586 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2025-03-06T18:52:27.354Z,1741287147.354 [BackseatComponent](FAULT): Failed to receive device response within the specified timeout.
2025-03-06T18:52:27.354Z,1741287147.354 [BackseatComponent] Communications Fault, FailCount= 5
2025-03-06T18:52:27.354Z,1741287147.354 [BackseatComponent](ERROR): Communications Fault
2025-03-06T18:52:27.354Z,1741287147.354 [Power24vConverter] Hardware Fault, FailCount= 1
2025-03-06T18:52:27.354Z,1741287147.354 [Power24vConverter](ERROR): Hardware Fault
2025-03-06T18:52:27.608Z,1741287147.608 [Power24vConverter](INFO): Powering down.
2025-03-06T18:52:27.646Z,1741287147.646 [CBIT](ERROR): Communications Fault in component: BackseatComponent
2025-03-06T18:52:27.647Z,1741287147.647 [CBIT](CRITICAL): Communications Fault in component: BackseatComponent
2025-03-06T18:52:27.647Z,1741287147.647 [CBIT](ERROR): Hardware Fault in component: Power24vConverter
2025-03-06T18:52:27.759Z,1741287147.759 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T18:52:27.760Z,1741287147.760 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T18:52:28.031Z,1741287148.031 [CommandExec](FAULT): Scheduling is paused
2025-03-06T18:52:28.032Z,1741287148.032 [CBIT](INFO): Critical error at 20250306T185227
2025-03-06T18:52:28.032Z,1741287148.032 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-03-06T18:52:28.430Z,1741287148.430 [Power24vConverter](INFO): Powering up.
2025-03-06T18:52:28.449Z,1741287148.449 [MissionManager](INFO): MissionManager is completed.
2025-03-06T18:52:28.450Z,1741287148.450 [MissionManager](INFO): Uninitializing Mission run_backseat_on_surface
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface] Stopped
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface](DEBUG): Aggregate::uninitialize run_backseat_on_surface
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:BackseatDriver] Stopped
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:BackseatDriver](DEBUG): Aggregate::uninitialize run_backseat_on_surface:BackseatDriver
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver] Stopped
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:PowerOnly] Stopped
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:PowerOnly](DEBUG): Aggregate::uninitialize run_backseat_on_surface:PowerOnly
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:PowerOnly:E.Wait] Stopped
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T18:52:28.450Z,1741287148.450 [run_backseat_on_surface:D.GoToSurface] Stopped
2025-03-06T18:52:28.451Z,1741287148.451 [run_backseat_on_surface:D.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T18:52:28.451Z,1741287148.451 [run_backseat_on_surface:CheckIn] Stopped
2025-03-06T18:52:28.451Z,1741287148.451 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2025-03-06T18:52:28.451Z,1741287148.451 [run_backseat_on_surface:CheckIn:C.Wait] Stopped
2025-03-06T18:52:28.451Z,1741287148.451 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T18:52:28.524Z,1741287148.524 [CBIT](INFO): Clearing failed state for component Power24vConverter
2025-03-06T18:52:28.524Z,1741287148.524 [Power24vConverter] No Fault, FailCount= 1
2025-03-06T18:52:28.530Z,1741287148.530 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T18:52:28.849Z,1741287148.849 [MissionManager](IMPORTANT): Started mission Default
2025-03-06T18:52:28.849Z,1741287148.849 [Default] Running Loop=1
2025-03-06T18:52:28.850Z,1741287148.850 [Default](DEBUG): Aggregate::initialize Default
2025-03-06T18:52:28.850Z,1741287148.850 [Default:B.GoToSurface] Running Loop=1
2025-03-06T18:52:28.850Z,1741287148.850 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T18:52:28.850Z,1741287148.850 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T18:52:28.850Z,1741287148.850 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T18:52:28.851Z,1741287148.851 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T18:52:28.851Z,1741287148.851 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T18:52:28.851Z,1741287148.851 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T18:52:28.851Z,1741287148.851 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T18:52:28.852Z,1741287148.852 [Default:A.Wait] Running Loop=1
2025-03-06T18:52:28.852Z,1741287148.852 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:52:38.319Z,1741287158.319 [CommandExec](IMPORTANT): got command get BackseatComponent.loadControl
2025-03-06T18:52:38.320Z,1741287158.320 [CommandExec](IMPORTANT): BackseatComponent.loadControl /dev/loadC3
2025-03-06T18:52:42.172Z,1741287162.172 [Default:A.Wait](INFO): Done Waiting.
2025-03-06T18:52:42.173Z,1741287162.173 [Default:A.Wait] Stopped
2025-03-06T18:52:42.173Z,1741287162.173 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T18:52:42.569Z,1741287162.569 [Default:CheckIn] Running Loop=1
2025-03-06T18:52:42.569Z,1741287162.569 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T18:52:42.569Z,1741287162.569 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T18:52:45.938Z,1741287165.938 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T18:52:45.939Z,1741287165.939 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T18:52:45.939Z,1741287165.939 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T18:54:57.560Z,1741287297.560 [CBIT](INFO): Clearing failed state for component BackseatComponent
2025-03-06T18:54:57.560Z,1741287297.560 [BackseatComponent] No Fault, FailCount= 5
2025-03-06T18:54:57.646Z,1741287297.646 [BackseatComponent](INFO): Powering up
2025-03-06T18:54:57.646Z,1741287297.646 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T18:55:01.163Z,1741287301.163 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2025-03-06T18:55:01.163Z,1741287301.163 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:55:01.173Z,1741287301.173 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:55:01.564Z,1741287301.564 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:55:01.564Z,1741287301.564 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2025-03-06T18:55:16.122Z,1741287316.122 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T18:55:18.530Z,1741287318.530 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T18:55:18.531Z,1741287318.531 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T18:55:18.580Z,1741287318.580 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T18:55:36.694Z,1741287336.694 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T18:55:36.694Z,1741287336.694 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T18:55:36.695Z,1741287336.695 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T18:56:14.470Z,1741287374.470 [CommandExec](IMPORTANT): got command stop
2025-03-06T18:56:14.470Z,1741287374.470 [CommandExec](IMPORTANT): Scheduling is paused
2025-03-06T18:57:24.560Z,1741287444.560 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-03-06T18:57:24.560Z,1741287444.560 [NAL9602] Data Fault, FailCount= 5
2025-03-06T18:57:24.560Z,1741287444.560 [NAL9602](ERROR): Data Fault
2025-03-06T18:57:24.605Z,1741287444.605 [CBIT](ERROR): Data Fault in component: NAL9602
2025-03-06T18:57:24.605Z,1741287444.605 [CBIT](CRITICAL): Data Fault in component: NAL9602
2025-03-06T18:57:24.967Z,1741287444.967 [NAL9602](INFO): Powering down
2025-03-06T18:57:24.983Z,1741287444.983 [CommandExec](FAULT): Scheduling is paused
2025-03-06T18:57:24.984Z,1741287444.984 [CBIT](INFO): Critical error at 20250306T185724
2025-03-06T18:57:42.752Z,1741287462.752 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-06T18:52:42.6Z
2025-03-06T18:57:42.752Z,1741287462.752 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T18:57:42.752Z,1741287462.752 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T18:57:50.053Z,1741287470.053 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20250306T180334/Courier0016.lzma
2025-03-06T18:57:51.055Z,1741287471.055 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0016.lzma.bak
2025-03-06T18:57:51.056Z,1741287471.056 [DataOverHttps](INFO): SBD MOMSN=24134753
2025-03-06T18:58:02.138Z,1741287482.138 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2025-03-06T18:58:02.138Z,1741287482.138 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T18:58:02.149Z,1741287482.149 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T18:58:02.569Z,1741287482.569 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T18:58:02.569Z,1741287482.569 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2025-03-06T18:58:06.479Z,1741287486.479 [DataOverHttps](INFO): Sending 633 bytes from file Logs/20250306T180334/Express0017.lzma
2025-03-06T18:58:07.479Z,1741287487.479 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0017.lzma.bak
2025-03-06T18:58:07.479Z,1741287487.479 [DataOverHttps](INFO): SBD MOMSN=24134761
2025-03-06T18:58:08.607Z,1741287488.607 [Default:CheckIn:Read_Iridium] Stopped
2025-03-06T18:58:08.608Z,1741287488.608 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-06T18:58:08.608Z,1741287488.608 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T18:59:24.585Z,1741287564.585 [CBIT](INFO): Clearing failed state for component NAL9602
2025-03-06T18:59:24.585Z,1741287564.585 [NAL9602] No Fault, FailCount= 5
2025-03-06T18:59:24.955Z,1741287564.955 [NAL9602](INFO): Powering up NAL9602
2025-03-06T18:59:35.867Z,1741287575.867 [NAL9602](INFO): NAL9602 initialized
2025-03-06T19:00:02.625Z,1741287602.625 [CommandExec](IMPORTANT): got command report mod BackseatComponent.component_avgCurrent
2025-03-06T19:00:02.958Z,1741287602.958 [Reporter](INFO): BackseatComponent.component_avgCurrent 0.000000 mA
2025-03-06T19:00:12.961Z,1741287612.961 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:00:12.961Z,1741287612.961 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:00:12.962Z,1741287612.962 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:00:12.963Z,1741287612.963 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:00:13.254Z,1741287613.254 [MissionManager](DEBUG): TethyslAPI: ./Missions/Maintenance/run_backseat_on_surface.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="run_backseat_on_surface">
    <DefineArg Name="ElapsedSinceMissionStarted">
        <Units:minute />
        <Value>0</Value>
    </DefineArg>
    <Insert Filename="Insert/BackseatDriver.tl" />
    <Assign>
        <Sequence />
        <Arg Name="BackseatDriver:EnableBackseat" />
        <True />
    </Assign>
    <Insert Filename="Insert/PowerOnly.tl" />
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="CheckIn">
        <Sequence Repeat="288" />
        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M" />
            <Universal:time_fix />
        </ReadDatum>
        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence />
                    <Setting>
                        <Guidance:Execute.command />
                        <String>Burn on</String>
                    </Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications />
        </ReadDatum>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Units:minute />
                <Value>5</Value>
            </Setting>
        </Guidance:Wait>
        <Assign>
            <Sequence />
            <Arg Name="ElapsedSinceMissionStarted" />
            <Elapsed>
                <Universal:mission_started />
            </Elapsed>
        </Assign>
        <Syslog Severity="Important">
            run_backseat_on_surface mission has been running for 
            <Arg Name="ElapsedSinceMissionStarted" />
            <Units:minute />
        </Syslog>
    </Aggregate>
    <Syslog Severity="Important">Restarting logs and run_backseat_on_surface mission.</Syslog>
    <Guidance:Execute>
        <Sequence />
        <Setting>
            <Guidance:Execute.command />
            <String>restart logs</String>
        </Setting>
    </Guidance:Execute>
</Mission>

2025-03-06T19:00:13.258Z,1741287613.258 [MissionManager](INFO): DefineArg run_backseat_on_surface.ElapsedSinceMissionStarted = 0.000000 min
2025-03-06T19:00:13.258Z,1741287613.258 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-03-06T19:00:13.258Z,1741287613.258 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-03-06T19:00:13.259Z,1741287613.259 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-03-06T19:00:13.277Z,1741287613.277 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Aggregate Id="BackseatDriver">
    <DefineArg Name="EnableBackseat">
        <False />
    </DefineArg>
    <Parallel />
    <Guidance:BackseatDriver>
        <Sequence />
        <Setting>
            <Guidance:BackseatDriver.powerBackseat />
            <Arg Name="EnableBackseat" />
        </Setting>
    </Guidance:BackseatDriver>
</Aggregate>

2025-03-06T19:00:13.280Z,1741287613.280 [MissionManager](INFO): DefineArg run_backseat_on_surface:BackseatDriver.EnableBackseat = 0 bool
2025-03-06T19:00:13.282Z,1741287613.282 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-03-06T19:00:13.325Z,1741287613.325 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2025-03-06T19:00:13.326Z,1741287613.326 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2025-03-06T19:00:13.327Z,1741287613.327 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2025-03-06T19:00:13.475Z,1741287613.475 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Aggregate Id="PowerOnly">
    <DefineArg Name="SampleAll">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad1">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad2">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad3">
        <False />
    </DefineArg>
    <DefineArg Name="EnabledPowerOnly">
        <Sensor:PowerOnly.loadAtStartup />
    </DefineArg>
    <Parallel />
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleAll" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.samplePowerOnly />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad1" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad1 />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad2" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad2 />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad3" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad3 />
    </ReadData>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Units:hour />
            <Value>99999</Value>
        </Setting>
    </Guidance:Wait>
</Aggregate>

2025-03-06T19:00:13.483Z,1741287613.483 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T19:00:13.486Z,1741287613.486 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleAll = 0 bool
2025-03-06T19:00:13.488Z,1741287613.488 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad1 = 0 bool
2025-03-06T19:00:13.490Z,1741287613.490 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad2 = 0 bool
2025-03-06T19:00:13.492Z,1741287613.492 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad3 = 0 bool
2025-03-06T19:00:13.531Z,1741287613.531 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.EnabledPowerOnly = 0 bool
2025-03-06T19:00:13.566Z,1741287613.566 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Construct Wait.
2025-03-06T19:00:13.568Z,1741287613.568 [run_backseat_on_surface:D.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-06T19:00:13.607Z,1741287613.607 [run_backseat_on_surface:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-06T19:00:13.609Z,1741287613.609 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-06T19:00:13.614Z,1741287613.614 [run_backseat_on_surface:G.Execute](DEBUG): Construct Execute.
2025-03-06T19:00:13.619Z,1741287613.619 [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 run_backseat_on_surface {
  arguments {
    ElapsedSinceMissionStarted = 0 minute
  }

  # Power the science payload.

#  insert id="Science" Insert/Science.tl

  # Power the Backseat payload.

  insert Insert/BackseatDriver.tl

  assign in sequence BackseatDriver:EnableBackseat = true

  insert Insert/PowerOnly.tl

  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=P2H {
        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 ElapsedSinceMissionStarted = elapsed ( Universal:mission_started )

    syslog important "run_backseat_on_surface mission has been running for "
         + ElapsedSinceMissionStarted~minute
  }

  syslog important "Restarting logs and run_backseat_on_surface mission."

  behavior Guidance:Execute {
    run in sequence

    set command = "restart logs"
  }
}


2025-03-06T19:00:13.621Z,1741287613.621 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:00:13.855Z,1741287613.855 [Default] Stopped
2025-03-06T19:00:13.855Z,1741287613.855 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-06T19:00:13.856Z,1741287613.856 [Default:B.GoToSurface] Stopped
2025-03-06T19:00:13.856Z,1741287613.856 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T19:00:13.856Z,1741287613.856 [Default:CheckIn] Stopped
2025-03-06T19:00:13.856Z,1741287613.856 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T19:00:13.856Z,1741287613.856 [Default:CheckIn:C.Wait] Stopped
2025-03-06T19:00:13.856Z,1741287613.856 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:00:13.856Z,1741287613.856 [MissionManager](IMPORTANT): Started mission run_backseat_on_surface
2025-03-06T19:00:13.856Z,1741287613.856 [run_backseat_on_surface] Running Loop=1
2025-03-06T19:00:13.856Z,1741287613.856 [run_backseat_on_surface](DEBUG): Aggregate::initialize run_backseat_on_surface
2025-03-06T19:00:13.856Z,1741287613.856 [run_backseat_on_surface:BackseatDriver] Running Loop=1
2025-03-06T19:00:13.857Z,1741287613.857 [run_backseat_on_surface:BackseatDriver](DEBUG): Aggregate::initialize run_backseat_on_surface:BackseatDriver
2025-03-06T19:00:13.857Z,1741287613.857 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-03-06T19:00:13.857Z,1741287613.857 [run_backseat_on_surface:PowerOnly] Running Loop=1
2025-03-06T19:00:13.857Z,1741287613.857 [run_backseat_on_surface:PowerOnly](DEBUG): Aggregate::initialize run_backseat_on_surface:PowerOnly
2025-03-06T19:00:13.857Z,1741287613.857 [run_backseat_on_surface:PowerOnly:A] Running Loop=1
2025-03-06T19:00:13.857Z,1741287613.857 [run_backseat_on_surface:PowerOnly:B] Running Loop=1
2025-03-06T19:00:13.873Z,1741287613.873 [run_backseat_on_surface:PowerOnly:C] Running Loop=1
2025-03-06T19:00:13.873Z,1741287613.873 [run_backseat_on_surface:PowerOnly:D] Running Loop=1
2025-03-06T19:00:13.874Z,1741287613.874 [run_backseat_on_surface:PowerOnly:E.Wait] Running Loop=1
2025-03-06T19:00:13.874Z,1741287613.874 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:00:13.874Z,1741287613.874 [run_backseat_on_surface:D.GoToSurface] Running Loop=1
2025-03-06T19:00:13.874Z,1741287613.874 [run_backseat_on_surface:D.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T19:00:13.874Z,1741287613.874 [run_backseat_on_surface:D.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T19:00:13.874Z,1741287613.874 [run_backseat_on_surface:D.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T19:00:13.875Z,1741287613.875 [run_backseat_on_surface:D.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T19:00:13.875Z,1741287613.875 [run_backseat_on_surface:D.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T19:00:13.875Z,1741287613.875 [run_backseat_on_surface:D.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T19:00:13.876Z,1741287613.876 [run_backseat_on_surface:D.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T19:00:13.876Z,1741287613.876 [run_backseat_on_surface:B] Running Loop=1
2025-03-06T19:00:13.877Z,1741287613.877 [run_backseat_on_surface:PowerOnly] Running Loop=1
2025-03-06T19:00:13.881Z,1741287613.881 [run_backseat_on_surface:PowerOnly:D] Stopped
2025-03-06T19:00:13.881Z,1741287613.881 [run_backseat_on_surface:PowerOnly:C] Stopped
2025-03-06T19:00:13.882Z,1741287613.882 [run_backseat_on_surface:PowerOnly:B] Stopped
2025-03-06T19:00:13.882Z,1741287613.882 [run_backseat_on_surface:PowerOnly:A] Stopped
2025-03-06T19:00:13.882Z,1741287613.882 [run_backseat_on_surface:B] Stopped
2025-03-06T19:00:13.882Z,1741287613.882 [run_backseat_on_surface:BackseatDriver] Running Loop=1
2025-03-06T19:00:13.882Z,1741287613.882 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-03-06T19:00:13.974Z,1741287613.974 [BackseatComponent](INFO): Powering up
2025-03-06T19:00:13.974Z,1741287613.974 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T19:00:14.276Z,1741287614.276 [run_backseat_on_surface:CheckIn] Running Loop=1
2025-03-06T19:00:14.276Z,1741287614.276 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2025-03-06T19:00:14.276Z,1741287614.276 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:00:14.680Z,1741287614.680 [run_backseat_on_surface:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-06T19:00:32.463Z,1741287632.463 [Reporter](INFO): BackseatComponent.component_avgCurrent 0.000000 mA
2025-03-06T19:00:37.720Z,1741287637.720 [Reporter](INFO): BackseatComponent.component_avgCurrent 444.070007 mA
2025-03-06T19:00:47.404Z,1741287647.404 [Reporter](INFO): BackseatComponent.component_avgCurrent 455.080017 mA
2025-03-06T19:00:57.516Z,1741287657.516 [Reporter](INFO): BackseatComponent.component_avgCurrent 444.070007 mA
2025-03-06T19:01:03.143Z,1741287663.143 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2025-03-06T19:01:03.143Z,1741287663.143 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T19:01:03.158Z,1741287663.158 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T19:01:03.574Z,1741287663.574 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T19:01:03.574Z,1741287663.574 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2025-03-06T19:01:07.624Z,1741287667.624 [Reporter](INFO): BackseatComponent.component_avgCurrent 433.059998 mA
2025-03-06T19:01:17.716Z,1741287677.716 [Reporter](INFO): BackseatComponent.component_avgCurrent 466.089996 mA
2025-03-06T19:01:27.412Z,1741287687.412 [Reporter](INFO): BackseatComponent.component_avgCurrent 418.380005 mA
2025-03-06T19:01:37.516Z,1741287697.516 [Reporter](INFO): BackseatComponent.component_avgCurrent 462.420013 mA
2025-03-06T19:01:47.628Z,1741287707.628 [Reporter](INFO): BackseatComponent.component_avgCurrent 440.400024 mA
2025-03-06T19:02:07.416Z,1741287727.416 [Reporter](INFO): BackseatComponent.component_avgCurrent 458.750000 mA
2025-03-06T19:02:17.507Z,1741287737.507 [Reporter](INFO): BackseatComponent.component_avgCurrent 422.050018 mA
2025-03-06T19:02:27.592Z,1741287747.592 [Reporter](INFO): BackseatComponent.component_avgCurrent 466.089996 mA
2025-03-06T19:02:37.720Z,1741287757.720 [Reporter](INFO): BackseatComponent.component_avgCurrent 433.059998 mA
2025-03-06T19:02:47.408Z,1741287767.408 [Reporter](INFO): BackseatComponent.component_avgCurrent 447.740021 mA
2025-03-06T19:02:48.230Z,1741287768.230 [CommandExec](IMPORTANT): got command stop
2025-03-06T19:02:48.230Z,1741287768.230 [CommandExec](IMPORTANT): Scheduling is paused
2025-03-06T19:02:48.230Z,1741287768.230 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-03-06T19:02:48.601Z,1741287768.601 [MissionManager](INFO): MissionManager is completed.
2025-03-06T19:02:48.602Z,1741287768.602 [MissionManager](INFO): Uninitializing Mission run_backseat_on_surface
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface] Stopped
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface](DEBUG): Aggregate::uninitialize run_backseat_on_surface
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:BackseatDriver] Stopped
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:BackseatDriver](DEBUG): Aggregate::uninitialize run_backseat_on_surface:BackseatDriver
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver] Stopped
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:PowerOnly] Stopped
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:PowerOnly](DEBUG): Aggregate::uninitialize run_backseat_on_surface:PowerOnly
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:PowerOnly:E.Wait] Stopped
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:D.GoToSurface] Stopped
2025-03-06T19:02:48.602Z,1741287768.602 [run_backseat_on_surface:D.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T19:02:48.603Z,1741287768.603 [run_backseat_on_surface:CheckIn] Stopped
2025-03-06T19:02:48.603Z,1741287768.603 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2025-03-06T19:02:48.603Z,1741287768.603 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2025-03-06T19:02:49.011Z,1741287769.011 [MissionManager](IMPORTANT): Started mission Default
2025-03-06T19:02:49.011Z,1741287769.011 [Default] Running Loop=1
2025-03-06T19:02:49.011Z,1741287769.011 [Default](DEBUG): Aggregate::initialize Default
2025-03-06T19:02:49.011Z,1741287769.011 [Default:B.GoToSurface] Running Loop=1
2025-03-06T19:02:49.011Z,1741287769.011 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T19:02:49.012Z,1741287769.012 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T19:02:49.012Z,1741287769.012 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T19:02:49.012Z,1741287769.012 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T19:02:49.013Z,1741287769.013 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T19:02:49.013Z,1741287769.013 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T19:02:49.013Z,1741287769.013 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T19:02:49.014Z,1741287769.014 [Default:A.Wait] Running Loop=1
2025-03-06T19:02:49.014Z,1741287769.014 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:02:49.867Z,1741287769.867 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T19:02:49.867Z,1741287769.867 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T19:02:50.222Z,1741287770.222 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T19:02:50.223Z,1741287770.223 [Reporter](INFO): BackseatComponent.component_avgCurrent 447.740021 mA
2025-03-06T19:03:02.334Z,1741287782.334 [Default:A.Wait](INFO): Done Waiting.
2025-03-06T19:03:02.334Z,1741287782.334 [Default:A.Wait] Stopped
2025-03-06T19:03:02.334Z,1741287782.334 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:03:02.744Z,1741287782.744 [Default:CheckIn] Running Loop=1
2025-03-06T19:03:02.744Z,1741287782.744 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T19:03:02.744Z,1741287782.744 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:03:08.042Z,1741287788.042 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T19:03:08.042Z,1741287788.042 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T19:03:08.043Z,1741287788.043 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T19:03:08.790Z,1741287788.790 [Power24vConverter](INFO): Powering down.
2025-03-06T19:04:04.149Z,1741287844.149 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2025-03-06T19:04:04.150Z,1741287844.150 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T19:04:04.160Z,1741287844.160 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T19:04:04.544Z,1741287844.544 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T19:04:04.544Z,1741287844.544 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2025-03-06T19:06:18.419Z,1741287978.419 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:06:18.419Z,1741287978.419 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:06:18.419Z,1741287978.419 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:06:18.421Z,1741287978.421 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:06:18.718Z,1741287978.718 [MissionManager](DEBUG): TethyslAPI: ./Missions/Maintenance/run_backseat_on_surface.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="run_backseat_on_surface">
    <DefineArg Name="ElapsedSinceMissionStarted">
        <Units:minute />
        <Value>0</Value>
    </DefineArg>
    <Insert Filename="Insert/BackseatDriver.tl" />
    <Assign>
        <Sequence />
        <Arg Name="BackseatDriver:EnableBackseat" />
        <True />
    </Assign>
    <Insert Filename="Insert/PowerOnly.tl" />
    <Guidance:GoToSurface>
        <Progression />
    </Guidance:GoToSurface>
    <Aggregate Id="CheckIn">
        <Sequence Repeat="288" />
        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M" />
            <Universal:time_fix />
        </ReadDatum>
        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence />
                    <Setting>
                        <Guidance:Execute.command />
                        <String>Burn on</String>
                    </Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications />
        </ReadDatum>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Units:minute />
                <Value>5</Value>
            </Setting>
        </Guidance:Wait>
        <Assign>
            <Sequence />
            <Arg Name="ElapsedSinceMissionStarted" />
            <Elapsed>
                <Universal:mission_started />
            </Elapsed>
        </Assign>
        <Syslog Severity="Important">
            run_backseat_on_surface mission has been running for 
            <Arg Name="ElapsedSinceMissionStarted" />
            <Units:minute />
        </Syslog>
    </Aggregate>
    <Syslog Severity="Important">Restarting logs and run_backseat_on_surface mission.</Syslog>
    <Guidance:Execute>
        <Sequence />
        <Setting>
            <Guidance:Execute.command />
            <String>restart logs</String>
        </Setting>
    </Guidance:Execute>
</Mission>

2025-03-06T19:06:18.723Z,1741287978.723 [MissionManager](INFO): DefineArg run_backseat_on_surface.ElapsedSinceMissionStarted = 0.000000 min
2025-03-06T19:06:18.724Z,1741287978.724 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-03-06T19:06:18.724Z,1741287978.724 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-03-06T19:06:18.725Z,1741287978.725 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-03-06T19:06:18.743Z,1741287978.743 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Aggregate Id="BackseatDriver">
    <DefineArg Name="EnableBackseat">
        <False />
    </DefineArg>
    <Parallel />
    <Guidance:BackseatDriver>
        <Sequence />
        <Setting>
            <Guidance:BackseatDriver.powerBackseat />
            <Arg Name="EnableBackseat" />
        </Setting>
    </Guidance:BackseatDriver>
</Aggregate>

2025-03-06T19:06:18.746Z,1741287978.746 [MissionManager](INFO): DefineArg run_backseat_on_surface:BackseatDriver.EnableBackseat = 0 bool
2025-03-06T19:06:18.748Z,1741287978.748 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-03-06T19:06:18.792Z,1741287978.792 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2025-03-06T19:06:18.792Z,1741287978.792 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2025-03-06T19:06:18.793Z,1741287978.793 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2025-03-06T19:06:18.899Z,1741287978.899 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Aggregate Id="PowerOnly">
    <DefineArg Name="SampleAll">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad1">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad2">
        <False />
    </DefineArg>
    <DefineArg Name="SampleLoad3">
        <False />
    </DefineArg>
    <DefineArg Name="EnabledPowerOnly">
        <Sensor:PowerOnly.loadAtStartup />
    </DefineArg>
    <Parallel />
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleAll" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.samplePowerOnly />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad1" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad1 />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad2" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad2 />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="SampleLoad3" />
            <And>
                <Arg Name="EnabledPowerOnly" />
            </And>
        </While>
        <Sensor:PowerOnly.sampleLoad3 />
    </ReadData>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Units:hour />
            <Value>99999</Value>
        </Setting>
    </Guidance:Wait>
</Aggregate>

2025-03-06T19:06:18.903Z,1741287978.903 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleAll = 0 bool
2025-03-06T19:06:18.904Z,1741287978.904 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad1 = 0 bool
2025-03-06T19:06:18.936Z,1741287978.936 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad2 = 0 bool
2025-03-06T19:06:18.938Z,1741287978.938 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.SampleLoad3 = 0 bool
2025-03-06T19:06:18.940Z,1741287978.940 [MissionManager](INFO): DefineArg run_backseat_on_surface:PowerOnly.EnabledPowerOnly = 0 bool
2025-03-06T19:06:18.947Z,1741287978.947 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Construct Wait.
2025-03-06T19:06:18.949Z,1741287978.949 [run_backseat_on_surface:D.GoToSurface](DEBUG): Construct GoToSurface.
2025-03-06T19:06:18.996Z,1741287978.996 [run_backseat_on_surface:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-03-06T19:06:18.999Z,1741287978.999 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-03-06T19:06:19.003Z,1741287979.003 [run_backseat_on_surface:G.Execute](DEBUG): Construct Execute.
2025-03-06T19:06:19.009Z,1741287979.009 [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 run_backseat_on_surface {
  arguments {
    ElapsedSinceMissionStarted = 0 minute
  }

  # Power the science payload.

#  insert id="Science" Insert/Science.tl

  # Power the Backseat payload.

  insert Insert/BackseatDriver.tl

  assign in sequence BackseatDriver:EnableBackseat = true

  insert Insert/PowerOnly.tl

  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=P2H {
        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 ElapsedSinceMissionStarted = elapsed ( Universal:mission_started )

    syslog important "run_backseat_on_surface mission has been running for "
         + ElapsedSinceMissionStarted~minute
  }

  syslog important "Restarting logs and run_backseat_on_surface mission."

  behavior Guidance:Execute {
    run in sequence

    set command = "restart logs"
  }
}


2025-03-06T19:06:19.017Z,1741287979.017 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/run_backseat_on_surface.tl
2025-03-06T19:06:19.090Z,1741287979.090 [Default] Stopped
2025-03-06T19:06:19.091Z,1741287979.091 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-06T19:06:19.091Z,1741287979.091 [Default:B.GoToSurface] Stopped
2025-03-06T19:06:19.091Z,1741287979.091 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T19:06:19.091Z,1741287979.091 [Default:CheckIn] Stopped
2025-03-06T19:06:19.091Z,1741287979.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T19:06:19.091Z,1741287979.091 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T19:06:19.091Z,1741287979.091 [MissionManager](IMPORTANT): Started mission run_backseat_on_surface
2025-03-06T19:06:19.091Z,1741287979.091 [run_backseat_on_surface] Running Loop=1
2025-03-06T19:06:19.091Z,1741287979.091 [run_backseat_on_surface](DEBUG): Aggregate::initialize run_backseat_on_surface
2025-03-06T19:06:19.091Z,1741287979.091 [run_backseat_on_surface:BackseatDriver] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:BackseatDriver](DEBUG): Aggregate::initialize run_backseat_on_surface:BackseatDriver
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly](DEBUG): Aggregate::initialize run_backseat_on_surface:PowerOnly
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly:A] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly:B] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly:C] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly:D] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly:E.Wait] Running Loop=1
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:06:19.092Z,1741287979.092 [run_backseat_on_surface:D.GoToSurface] Running Loop=1
2025-03-06T19:06:19.093Z,1741287979.093 [run_backseat_on_surface:D.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T19:06:19.093Z,1741287979.093 [run_backseat_on_surface:D.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T19:06:19.093Z,1741287979.093 [run_backseat_on_surface:D.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T19:06:19.094Z,1741287979.094 [run_backseat_on_surface:D.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T19:06:19.094Z,1741287979.094 [run_backseat_on_surface:D.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T19:06:19.094Z,1741287979.094 [run_backseat_on_surface:D.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T19:06:19.095Z,1741287979.095 [run_backseat_on_surface:D.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T19:06:19.095Z,1741287979.095 [run_backseat_on_surface:B] Running Loop=1
2025-03-06T19:06:19.096Z,1741287979.096 [run_backseat_on_surface:PowerOnly] Running Loop=1
2025-03-06T19:06:19.096Z,1741287979.096 [run_backseat_on_surface:PowerOnly:D] Stopped
2025-03-06T19:06:19.096Z,1741287979.096 [run_backseat_on_surface:PowerOnly:C] Stopped
2025-03-06T19:06:19.096Z,1741287979.096 [run_backseat_on_surface:PowerOnly:B] Stopped
2025-03-06T19:06:19.096Z,1741287979.096 [run_backseat_on_surface:PowerOnly:A] Stopped
2025-03-06T19:06:19.096Z,1741287979.096 [run_backseat_on_surface:B] Stopped
2025-03-06T19:06:19.097Z,1741287979.097 [run_backseat_on_surface:BackseatDriver] Running Loop=1
2025-03-06T19:06:19.097Z,1741287979.097 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-03-06T19:06:19.159Z,1741287979.159 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T19:06:19.222Z,1741287979.222 [BackseatComponent](INFO): Powering up
2025-03-06T19:06:19.222Z,1741287979.222 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T19:06:19.460Z,1741287979.460 [Power24vConverter](INFO): Powering up.
2025-03-06T19:06:19.468Z,1741287979.468 [run_backseat_on_surface:CheckIn] Running Loop=1
2025-03-06T19:06:19.468Z,1741287979.468 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2025-03-06T19:06:19.469Z,1741287979.469 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:06:19.876Z,1741287979.876 [run_backseat_on_surface:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-03-06T19:06:37.696Z,1741287997.696 [Reporter](INFO): BackseatComponent.component_avgCurrent 0.000000 mA
2025-03-06T19:06:45.358Z,1741288005.358 [Reporter](INFO): BackseatComponent.component_avgCurrent 7.340000 mA
2025-03-06T19:07:05.144Z,1741288025.144 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21
2025-03-06T19:07:05.144Z,1741288025.144 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-03-06T19:07:05.158Z,1741288025.158 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-03-06T19:07:05.538Z,1741288025.538 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-03-06T19:07:05.538Z,1741288025.538 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21
2025-03-06T19:08:00.871Z,1741288080.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190759.00,A,3648.14689,N,12147.30570,W,1.536,227.85,060325,,,A*7D
2025-03-06T19:08:00.874Z,1741288080.874 [NAL9602](INFO): GPS fix at 20250306T190759: (36.802448, -121.788428)
2025-03-06T19:08:00.886Z,1741288080.886 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2025-03-06T19:08:00.886Z,1741288080.886 [run_backseat_on_surface:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T19:08:01.305Z,1741288081.305 [run_backseat_on_surface:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-03-06T19:08:07.762Z,1741288087.762 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20250306T180334/Courier0019.lzma
2025-03-06T19:08:08.763Z,1741288088.763 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0019.lzma.bak
2025-03-06T19:08:08.763Z,1741288088.763 [DataOverHttps](INFO): SBD MOMSN=24134846
2025-03-06T19:08:24.579Z,1741288104.579 [DataOverHttps](INFO): Sending 476 bytes from file Logs/20250306T180334/Express0020.lzma
2025-03-06T19:08:25.575Z,1741288105.575 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0020.lzma.bak
2025-03-06T19:08:25.575Z,1741288105.575 [DataOverHttps](INFO): SBD MOMSN=24134849
2025-03-06T19:08:26.743Z,1741288106.743 [run_backseat_on_surface:CheckIn:Read_Iridium] Stopped
2025-03-06T19:08:26.743Z,1741288106.743 [run_backseat_on_surface:CheckIn:C.Wait] Running Loop=1
2025-03-06T19:08:26.743Z,1741288106.743 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:08:33.204Z,1741288113.204 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-06T19:08:41.666Z,1741288121.666 [CommandExec](IMPORTANT): got command stop
2025-03-06T19:08:41.666Z,1741288121.666 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-03-06T19:08:41.693Z,1741288121.693 [MissionManager](INFO): MissionManager is completed.
2025-03-06T19:08:41.694Z,1741288121.694 [MissionManager](INFO): Uninitializing Mission run_backseat_on_surface
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface] Stopped
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface](DEBUG): Aggregate::uninitialize run_backseat_on_surface
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:BackseatDriver] Stopped
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:BackseatDriver](DEBUG): Aggregate::uninitialize run_backseat_on_surface:BackseatDriver
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:BackseatDriver:A.BackseatDriver] Stopped
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:PowerOnly] Stopped
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:PowerOnly](DEBUG): Aggregate::uninitialize run_backseat_on_surface:PowerOnly
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:PowerOnly:E.Wait] Stopped
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:08:41.694Z,1741288121.694 [run_backseat_on_surface:D.GoToSurface] Stopped
2025-03-06T19:08:41.695Z,1741288121.695 [run_backseat_on_surface:D.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T19:08:41.695Z,1741288121.695 [run_backseat_on_surface:CheckIn] Stopped
2025-03-06T19:08:41.695Z,1741288121.695 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2025-03-06T19:08:41.695Z,1741288121.695 [run_backseat_on_surface:CheckIn:C.Wait] Stopped
2025-03-06T19:08:41.695Z,1741288121.695 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:08:42.095Z,1741288122.095 [MissionManager](IMPORTANT): Started mission Default
2025-03-06T19:08:42.095Z,1741288122.095 [Default] Running Loop=1
2025-03-06T19:08:42.095Z,1741288122.095 [Default](DEBUG): Aggregate::initialize Default
2025-03-06T19:08:42.095Z,1741288122.095 [Default:B.GoToSurface] Running Loop=1
2025-03-06T19:08:42.095Z,1741288122.095 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T19:08:42.095Z,1741288122.095 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T19:08:42.096Z,1741288122.096 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T19:08:42.096Z,1741288122.096 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T19:08:42.096Z,1741288122.096 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T19:08:42.097Z,1741288122.097 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T19:08:42.097Z,1741288122.097 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T19:08:42.098Z,1741288122.098 [Default:A.Wait] Running Loop=1
2025-03-06T19:08:42.098Z,1741288122.098 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:08:42.623Z,1741288122.623 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T19:08:42.623Z,1741288122.623 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T19:08:42.907Z,1741288122.907 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T19:08:42.907Z,1741288122.907 [Reporter](INFO): BackseatComponent.component_avgCurrent 7.340000 mA
2025-03-06T19:08:55.421Z,1741288135.421 [Default:A.Wait](INFO): Done Waiting.
2025-03-06T19:08:55.421Z,1741288135.421 [Default:A.Wait] Stopped
2025-03-06T19:08:55.421Z,1741288135.421 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:08:55.825Z,1741288135.825 [Default:CheckIn] Running Loop=1
2025-03-06T19:08:55.825Z,1741288135.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T19:08:55.825Z,1741288135.825 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:08:57.835Z,1741288137.835 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190857.00,A,3648.16685,N,12147.28010,W,0.486,227.85,060325,,,A*73
2025-03-06T19:08:57.837Z,1741288137.837 [NAL9602](INFO): GPS fix at 20250306T190857: (36.802781, -121.788002)
2025-03-06T19:08:57.847Z,1741288137.847 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T19:08:57.847Z,1741288137.847 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T19:09:00.798Z,1741288140.798 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T19:09:00.798Z,1741288140.798 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T19:09:00.799Z,1741288140.799 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T19:09:05.477Z,1741288145.477 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250306T180334/Courier0022.lzma
2025-03-06T19:09:06.480Z,1741288146.480 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0022.lzma.bak
2025-03-06T19:09:06.480Z,1741288146.480 [DataOverHttps](INFO): SBD MOMSN=24134862
2025-03-06T19:09:22.225Z,1741288162.225 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20250306T180334/Express0023.lzma
2025-03-06T19:09:23.227Z,1741288163.227 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0023.lzma.bak
2025-03-06T19:09:23.227Z,1741288163.227 [DataOverHttps](INFO): SBD MOMSN=24134865
2025-03-06T19:09:24.507Z,1741288164.507 [Default:CheckIn:Read_Iridium] Stopped
2025-03-06T19:09:24.508Z,1741288164.508 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-06T19:09:24.508Z,1741288164.508 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:12:40.464Z,1741288360.464 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:12:53.843Z,1741288373.843 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:13:00.352Z,1741288380.352 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T19:13:48.389Z,1741288428.389 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:14:00.447Z,1741288440.447 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-03-06T19:14:20.291Z,1741288460.291 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T19:14:25.104Z,1741288465.104 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-03-06T19:14:25.104Z,1741288465.104 [Default:CheckIn:C.Wait] Stopped
2025-03-06T19:14:25.104Z,1741288465.104 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:14:25.105Z,1741288465.105 [Default:CheckIn:D] Running Loop=1
2025-03-06T19:14:25.505Z,1741288465.505 [Default:CheckIn:D] Stopped
2025-03-06T19:14:25.505Z,1741288465.505 [Default:CheckIn:E] Running Loop=1
2025-03-06T19:14:25.917Z,1741288465.917 [Default:CheckIn:E](IMPORTANT): Default mission has been running for  5.723494 min 
2025-03-06T19:14:25.917Z,1741288465.917 [Default:CheckIn:E] Stopped
2025-03-06T19:14:25.918Z,1741288465.918 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-03-06T19:14:25.918Z,1741288465.918 [Default:CheckIn] Stopped
2025-03-06T19:14:25.918Z,1741288465.918 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T19:14:25.918Z,1741288465.918 [Default:CheckIn](INFO): Running loop #2
2025-03-06T19:14:25.918Z,1741288465.918 [Default:CheckIn] Running Loop=2
2025-03-06T19:14:25.918Z,1741288465.918 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T19:14:25.918Z,1741288465.918 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:14:36.813Z,1741288476.813 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191436.00,A,3648.15582,N,12147.30584,W,2.449,0.00,060325,,,A*74
2025-03-06T19:14:36.815Z,1741288476.815 [NAL9602](INFO): GPS fix at 20250306T191436: (36.802597, -121.788431)
2025-03-06T19:14:36.825Z,1741288476.825 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T19:14:36.825Z,1741288476.825 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T19:14:44.521Z,1741288484.521 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250306T180334/Courier0025.lzma
2025-03-06T19:14:45.523Z,1741288485.523 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0025.lzma.bak
2025-03-06T19:14:45.523Z,1741288485.523 [DataOverHttps](INFO): SBD MOMSN=24134887
2025-03-06T19:15:01.526Z,1741288501.526 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20250306T180334/Express0026.lzma
2025-03-06T19:15:02.527Z,1741288502.527 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0026.lzma.bak
2025-03-06T19:15:02.527Z,1741288502.527 [DataOverHttps](INFO): SBD MOMSN=24134891
2025-03-06T19:15:03.880Z,1741288503.880 [Default:CheckIn:Read_Iridium] Stopped
2025-03-06T19:15:03.881Z,1741288503.881 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-06T19:15:03.881Z,1741288503.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:15:09.529Z,1741288509.529 [NAL9602](INFO): Not Powering down - fast GPS
2025-03-06T19:15:10.414Z,1741288510.414 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:15:21.698Z,1741288521.698 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T19:15:53.209Z,1741288553.209 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:16:08.598Z,1741288568.598 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T19:16:21.905Z,1741288581.905 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T19:16:54.674Z,1741288614.674 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:17:02.708Z,1741288622.708 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T19:17:37.811Z,1741288657.811 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:17:50.381Z,1741288670.381 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:18:51.386Z,1741288731.386 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-03-06T19:18:59.064Z,1741288739.064 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-03-06T19:19:01.827Z,1741288741.827 [Power24vConverter](INFO): Powering down.
2025-03-06T19:19:50.891Z,1741288790.891 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_test.xml
2025-03-06T19:19:50.891Z,1741288790.891 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_test.xml
2025-03-06T19:19:51.012Z,1741288791.012 [MissionManager](INFO): DefineArg multiray_test.MissionTimeout = 5.000000 min
2025-03-06T19:19:51.019Z,1741288791.019 [MissionManager](INFO): DefineArg multiray_test.LightDuration = 5.000000 s
2025-03-06T19:19:51.063Z,1741288791.063 [MissionManager](INFO): DefineArg multiray_test.LightMode0 = 0.000000 count
2025-03-06T19:19:51.070Z,1741288791.070 [MissionManager](INFO): DefineArg multiray_test.LightMode1 = 1.000000 count
2025-03-06T19:19:51.073Z,1741288791.073 [MissionManager](INFO): DefineArg multiray_test.LightMode2 = 2.000000 count
2025-03-06T19:19:51.097Z,1741288791.097 [MissionManager](INFO): DefineArg multiray_test.EnabledMultiray = 1 bool
2025-03-06T19:19:51.109Z,1741288791.109 [multiray_test:C.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.131Z,1741288791.131 [multiray_test:E.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.175Z,1741288791.175 [multiray_test:G.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.194Z,1741288791.194 [multiray_test:I.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.197Z,1741288791.197 [multiray_test:K.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.200Z,1741288791.200 [multiray_test:M.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.228Z,1741288791.228 [multiray_test:O.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.251Z,1741288791.251 [multiray_test:Q.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.254Z,1741288791.254 [multiray_test:R.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.282Z,1741288791.282 [multiray_test:T.Wait](DEBUG): Construct Wait.
2025-03-06T19:19:51.297Z,1741288791.297 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!--
-   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 xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Units="Tethys/Units"
         xmlns:Sample="Tethys/Sample"
         xmlns:Sensor="Tethys/Sensor"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd"
       Id="multiray_test">

    <Description>
        This mission is designed to run in the lab only. Cycles through MultiRay
        light modes
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>5</Value></DefineArg>

    <DefineArg Name="LightDuration"><Description>
        How long to wait before changing light modes
    </Description><Units:second/><Value>5</Value></DefineArg>

    <DefineArg Name="LightMode0"><Description>
        Light mode = 0
    </Description><Units:count/><Value>0</Value></DefineArg>

    <DefineArg Name="LightMode1"><Description>
        Light mode = 1
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="LightMode2"><Description>
        Light mode = 2
    </Description><Units:count/><Value>2</Value></DefineArg>

    <DefineArg Name="EnabledMultiray"><Description>
        Automatically set to true if the Multiray is enabled.
    </Description><Science:MultiRay.loadAtStartup/></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledMultiray"/>
        </While>
        <Sensor:MultiRay.lightModeLog/>
    </ReadData>

<!-- <ReadDatum>
            <Sensor:MultiRay.lightModeLog/>
    </ReadDatum> -->

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode1"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode2"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode1"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode2"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode1"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode2"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
    </Guidance:Wait>

</Mission>


2025-03-06T19:19:51.299Z,1741288791.299 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_test.xml
2025-03-06T19:19:51.588Z,1741288791.588 [Default] Stopped
2025-03-06T19:19:51.588Z,1741288791.588 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-06T19:19:51.588Z,1741288791.588 [Default:B.GoToSurface] Stopped
2025-03-06T19:19:51.589Z,1741288791.589 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T19:19:51.589Z,1741288791.589 [Default:CheckIn] Stopped
2025-03-06T19:19:51.589Z,1741288791.589 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T19:19:51.589Z,1741288791.589 [Default:CheckIn:C.Wait] Stopped
2025-03-06T19:19:51.589Z,1741288791.589 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:19:51.589Z,1741288791.589 [MissionManager](IMPORTANT): Started mission multiray_test
2025-03-06T19:19:51.593Z,1741288791.593 [multiray_test] Running Loop=1
2025-03-06T19:19:51.594Z,1741288791.594 [multiray_test](DEBUG): Aggregate::initialize multiray_test
2025-03-06T19:19:51.594Z,1741288791.594 [multiray_test:A] Running Loop=1
2025-03-06T19:19:51.594Z,1741288791.594 [multiray_test:B] Running Loop=1
2025-03-06T19:19:51.594Z,1741288791.594 [multiray_test:B] Stopped
2025-03-06T19:19:51.594Z,1741288791.594 [multiray_test:C.Wait] Running Loop=1
2025-03-06T19:19:51.595Z,1741288791.595 [multiray_test:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:19:51.595Z,1741288791.595 [multiray_test:A] Running Loop=1
2025-03-06T19:19:51.595Z,1741288791.595 [multiray_test:A](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-03-06T19:19:53.175Z,1741288793.175 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:19:53.986Z,1741288793.986 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:19:54.807Z,1741288794.807 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:19:55.595Z,1741288795.595 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:19:56.408Z,1741288796.408 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:19:57.215Z,1741288797.215 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:19:57.225Z,1741288797.225 [multiray_test:C.Wait](INFO): Done Waiting.
2025-03-06T19:19:57.225Z,1741288797.225 [multiray_test:C.Wait] Stopped
2025-03-06T19:19:57.225Z,1741288797.225 [multiray_test:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:19:57.225Z,1741288797.225 [multiray_test:D] Running Loop=1
2025-03-06T19:19:57.674Z,1741288797.674 [multiray_test:D] Stopped
2025-03-06T19:19:57.674Z,1741288797.674 [multiray_test:E.Wait] Running Loop=1
2025-03-06T19:19:57.674Z,1741288797.674 [multiray_test:E.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:20:03.290Z,1741288803.290 [multiray_test:E.Wait](INFO): Done Waiting.
2025-03-06T19:20:03.290Z,1741288803.290 [multiray_test:E.Wait] Stopped
2025-03-06T19:20:03.290Z,1741288803.290 [multiray_test:E.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:20:03.291Z,1741288803.291 [multiray_test:F] Running Loop=1
2025-03-06T19:20:03.757Z,1741288803.757 [multiray_test:F] Stopped
2025-03-06T19:20:03.757Z,1741288803.757 [multiray_test:G.Wait] Running Loop=1
2025-03-06T19:20:03.757Z,1741288803.757 [multiray_test:G.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:20:07.317Z,1741288807.317 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-03-06T19:20:07.320Z,1741288807.320 [BPC1](INFO): Received data from all battery sticks.
2025-03-06T19:20:09.345Z,1741288809.345 [multiray_test:G.Wait](INFO): Done Waiting.
2025-03-06T19:20:09.345Z,1741288809.345 [multiray_test:G.Wait] Stopped
2025-03-06T19:20:09.345Z,1741288809.345 [multiray_test:G.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:20:09.345Z,1741288809.345 [multiray_test:H] Running Loop=1
2025-03-06T19:20:09.783Z,1741288809.783 [multiray_test:H] Stopped
2025-03-06T19:20:09.783Z,1741288809.783 [multiray_test:I.Wait] Running Loop=1
2025-03-06T19:20:09.784Z,1741288809.784 [multiray_test:I.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:20:10.547Z,1741288810.547 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:20:11.350Z,1741288811.350 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:20:11.934Z,1741288811.934 [CommandExec](IMPORTANT): got command stop
2025-03-06T19:20:11.934Z,1741288811.934 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-03-06T19:20:12.159Z,1741288812.159 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:20:12.169Z,1741288812.169 [MissionManager](INFO): MissionManager is completed.
2025-03-06T19:20:12.169Z,1741288812.169 [MissionManager](INFO): Uninitializing Mission multiray_test
2025-03-06T19:20:12.169Z,1741288812.169 [multiray_test] Stopped
2025-03-06T19:20:12.169Z,1741288812.169 [multiray_test](DEBUG): Aggregate::uninitialize multiray_test
2025-03-06T19:20:12.169Z,1741288812.169 [multiray_test:A] Stopped
2025-03-06T19:20:12.169Z,1741288812.169 [multiray_test:I.Wait] Stopped
2025-03-06T19:20:12.169Z,1741288812.169 [multiray_test:I.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:20:12.578Z,1741288812.578 [MissionManager](IMPORTANT): Started mission Default
2025-03-06T19:20:12.578Z,1741288812.578 [Default] Running Loop=1
2025-03-06T19:20:12.578Z,1741288812.578 [Default](DEBUG): Aggregate::initialize Default
2025-03-06T19:20:12.578Z,1741288812.578 [Default:B.GoToSurface] Running Loop=1
2025-03-06T19:20:12.578Z,1741288812.578 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T19:20:12.578Z,1741288812.578 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T19:20:12.579Z,1741288812.579 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T19:20:12.579Z,1741288812.579 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T19:20:12.579Z,1741288812.579 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T19:20:12.580Z,1741288812.580 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T19:20:12.580Z,1741288812.580 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T19:20:12.580Z,1741288812.580 [Default:A.Wait] Running Loop=1
2025-03-06T19:20:12.580Z,1741288812.580 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:20:25.946Z,1741288825.946 [Default:A.Wait](INFO): Done Waiting.
2025-03-06T19:20:25.946Z,1741288825.946 [Default:A.Wait] Stopped
2025-03-06T19:20:25.946Z,1741288825.946 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:20:26.339Z,1741288826.339 [Default:CheckIn] Running Loop=1
2025-03-06T19:20:26.339Z,1741288826.339 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T19:20:26.340Z,1741288826.340 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:20:28.321Z,1741288828.321 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192027.00,A,3648.17136,N,12147.29930,W,0.194,243.42,060325,,,A*75
2025-03-06T19:20:28.323Z,1741288828.323 [NAL9602](INFO): GPS fix at 20250306T192027: (36.802856, -121.788322)
2025-03-06T19:20:28.353Z,1741288828.353 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T19:20:28.353Z,1741288828.353 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-03-06T19:20:29.438Z,1741288829.438 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20250306T180334/Courier0028.lzma
2025-03-06T19:20:30.435Z,1741288830.435 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Courier0028.lzma.bak
2025-03-06T19:20:30.435Z,1741288830.435 [DataOverHttps](INFO): SBD MOMSN=24134907
2025-03-06T19:20:46.650Z,1741288846.650 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20250306T180334/Express0029.lzma
2025-03-06T19:20:47.651Z,1741288847.651 [DataOverHttps](INFO): Moved sent file to Logs/20250306T180334/Express0029.lzma.bak
2025-03-06T19:20:47.651Z,1741288847.651 [DataOverHttps](INFO): SBD MOMSN=24134910
2025-03-06T19:20:48.936Z,1741288848.936 [Default:CheckIn:Read_Iridium] Stopped
2025-03-06T19:20:48.936Z,1741288848.936 [Default:CheckIn:C.Wait] Running Loop=1
2025-03-06T19:20:48.936Z,1741288848.936 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:20:59.027Z,1741288859.027 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-03-06T19:20:59.109Z,1741288859.109 [NAL9602](ERROR): received: 
+CSQ:0

OK
2025-03-06T19:21:14.985Z,1741288874.985 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/multiray_test.tl
2025-03-06T19:21:14.986Z,1741288874.986 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/multiray_test.tl
2025-03-06T19:21:14.986Z,1741288874.986 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/multiray_test.tl
2025-03-06T19:21:14.987Z,1741288874.987 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/multiray_test.tl
2025-03-06T19:21:15.431Z,1741288875.431 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/multiray_test.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="multiray_test">
    <DefineArg Name="MissionTimeout">
        <Units:minute />
        <Value>5</Value>
    </DefineArg>
    <DefineArg Name="LightDuration">
        <Units:second />
        <Value>5</Value>
    </DefineArg>
    <DefineArg Name="LightMode0">
        <Units:count />
        <Value>0</Value>
    </DefineArg>
    <DefineArg Name="LightMode1">
        <Units:count />
        <Value>1</Value>
    </DefineArg>
    <DefineArg Name="LightMode2">
        <Units:count />
        <Value>2</Value>
    </DefineArg>
    <DefineArg Name="EnabledMultiray">
        <Sensor:MultiRay.loadAtStartup />
    </DefineArg>
    <Timeout Duration="MissionTimeout" />
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledMultiray" />
        </While>
        <Sensor:MultiRay.lightModeLog />
    </ReadData>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode0" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode1" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode2" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode0" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode1" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode2" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode0" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode1" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode2" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
    <Assign>
        <Sequence />
        <Sensor:MultiRay.lightModeCommand />
        <Arg Name="LightMode0" />
    </Assign>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="LightDuration" />
        </Setting>
    </Guidance:Wait>
</Mission>

2025-03-06T19:21:15.443Z,1741288875.443 [MissionManager](INFO): DefineArg multiray_test.MissionTimeout = 5.000000 min
2025-03-06T19:21:15.446Z,1741288875.446 [MissionManager](INFO): DefineArg multiray_test.LightDuration = 5.000000 s
2025-03-06T19:21:15.448Z,1741288875.448 [MissionManager](INFO): DefineArg multiray_test.LightMode0 = 0.000000 count
2025-03-06T19:21:15.514Z,1741288875.514 [MissionManager](INFO): DefineArg multiray_test.LightMode1 = 1.000000 count
2025-03-06T19:21:15.516Z,1741288875.516 [MissionManager](INFO): DefineArg multiray_test.LightMode2 = 2.000000 count
2025-03-06T19:21:15.519Z,1741288875.519 [MissionManager](INFO): DefineArg multiray_test.EnabledMultiray = 1 bool
2025-03-06T19:21:15.522Z,1741288875.522 [multiray_test:C.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.525Z,1741288875.525 [multiray_test:E.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.528Z,1741288875.528 [multiray_test:G.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.539Z,1741288875.539 [multiray_test:I.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.542Z,1741288875.542 [multiray_test:K.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.544Z,1741288875.544 [multiray_test:M.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.547Z,1741288875.547 [multiray_test:O.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.550Z,1741288875.550 [multiray_test:Q.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.553Z,1741288875.553 [multiray_test:R.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.644Z,1741288875.644 [multiray_test:T.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:15.682Z,1741288875.682 [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
  }

  # <ReadDatum>
  #            <Sensor:MultiRay.lightModeLog/>
  #    </ReadDatum>

  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-03-06T19:21:15.683Z,1741288875.683 [CommandExec](IMPORTANT): Running ./Missions/Engineering/multiray_test.tl
2025-03-06T19:21:15.689Z,1741288875.689 [Default] Stopped
2025-03-06T19:21:15.689Z,1741288875.689 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-06T19:21:15.689Z,1741288875.689 [Default:B.GoToSurface] Stopped
2025-03-06T19:21:15.689Z,1741288875.689 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T19:21:15.689Z,1741288875.689 [Default:CheckIn] Stopped
2025-03-06T19:21:15.689Z,1741288875.689 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T19:21:15.690Z,1741288875.690 [Default:CheckIn:C.Wait] Stopped
2025-03-06T19:21:15.690Z,1741288875.690 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:21:15.690Z,1741288875.690 [MissionManager](IMPORTANT): Started mission multiray_test
2025-03-06T19:21:15.690Z,1741288875.690 [multiray_test] Running Loop=1
2025-03-06T19:21:15.690Z,1741288875.690 [multiray_test](DEBUG): Aggregate::initialize multiray_test
2025-03-06T19:21:15.690Z,1741288875.690 [multiray_test:A] Running Loop=1
2025-03-06T19:21:15.691Z,1741288875.691 [multiray_test:B] Running Loop=1
2025-03-06T19:21:15.691Z,1741288875.691 [multiray_test:B] Stopped
2025-03-06T19:21:15.691Z,1741288875.691 [multiray_test:C.Wait] Running Loop=1
2025-03-06T19:21:15.692Z,1741288875.692 [multiray_test:C.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:21:15.692Z,1741288875.692 [multiray_test:A] Running Loop=1
2025-03-06T19:21:15.692Z,1741288875.692 [multiray_test:A](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-03-06T19:21:17.205Z,1741288877.205 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:21:18.011Z,1741288878.011 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:21:18.831Z,1741288878.831 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:21:19.627Z,1741288879.627 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:21:20.434Z,1741288880.434 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:21:21.258Z,1741288881.258 [MultiRay](INFO): All lights off failed! Try again next cycle
2025-03-06T19:21:21.314Z,1741288881.314 [multiray_test:C.Wait](INFO): Done Waiting.
2025-03-06T19:21:21.314Z,1741288881.314 [multiray_test:C.Wait] Stopped
2025-03-06T19:21:21.314Z,1741288881.314 [multiray_test:C.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:21:21.314Z,1741288881.314 [multiray_test:D] Running Loop=1
2025-03-06T19:21:21.719Z,1741288881.719 [multiray_test:D] Stopped
2025-03-06T19:21:21.719Z,1741288881.719 [multiray_test:E.Wait] Running Loop=1
2025-03-06T19:21:21.719Z,1741288881.719 [multiray_test:E.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:21:27.365Z,1741288887.365 [multiray_test:E.Wait](INFO): Done Waiting.
2025-03-06T19:21:27.365Z,1741288887.365 [multiray_test:E.Wait] Stopped
2025-03-06T19:21:27.365Z,1741288887.365 [multiray_test:E.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:21:27.365Z,1741288887.365 [multiray_test:F] Running Loop=1
2025-03-06T19:21:27.775Z,1741288887.775 [multiray_test:F] Stopped
2025-03-06T19:21:27.775Z,1741288887.775 [multiray_test:G.Wait] Running Loop=1
2025-03-06T19:21:27.775Z,1741288887.775 [multiray_test:G.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:21:29.074Z,1741288889.074 [CommandExec](IMPORTANT): got command stop
2025-03-06T19:21:29.074Z,1741288889.074 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-03-06T19:21:29.351Z,1741288889.351 [MissionManager](INFO): MissionManager is completed.
2025-03-06T19:21:29.351Z,1741288889.351 [MissionManager](INFO): Uninitializing Mission multiray_test
2025-03-06T19:21:29.351Z,1741288889.351 [multiray_test] Stopped
2025-03-06T19:21:29.351Z,1741288889.351 [multiray_test](DEBUG): Aggregate::uninitialize multiray_test
2025-03-06T19:21:29.351Z,1741288889.351 [multiray_test:A] Stopped
2025-03-06T19:21:29.351Z,1741288889.351 [multiray_test:G.Wait] Stopped
2025-03-06T19:21:29.351Z,1741288889.351 [multiray_test:G.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:21:29.762Z,1741288889.762 [MissionManager](IMPORTANT): Started mission Default
2025-03-06T19:21:29.762Z,1741288889.762 [Default] Running Loop=1
2025-03-06T19:21:29.762Z,1741288889.762 [Default](DEBUG): Aggregate::initialize Default
2025-03-06T19:21:29.762Z,1741288889.762 [Default:B.GoToSurface] Running Loop=1
2025-03-06T19:21:29.762Z,1741288889.762 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T19:21:29.762Z,1741288889.762 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T19:21:29.763Z,1741288889.763 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T19:21:29.763Z,1741288889.763 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T19:21:29.763Z,1741288889.763 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T19:21:29.764Z,1741288889.764 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T19:21:29.764Z,1741288889.764 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T19:21:29.764Z,1741288889.764 [Default:A.Wait] Running Loop=1
2025-03-06T19:21:29.764Z,1741288889.764 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:21:43.097Z,1741288903.097 [Default:A.Wait](INFO): Done Waiting.
2025-03-06T19:21:43.097Z,1741288903.097 [Default:A.Wait] Stopped
2025-03-06T19:21:43.097Z,1741288903.097 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:21:43.481Z,1741288903.481 [Default:CheckIn] Running Loop=1
2025-03-06T19:21:43.481Z,1741288903.481 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T19:21:43.481Z,1741288903.481 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:21:47.606Z,1741288907.606 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-03-06T19:21:47.606Z,1741288907.606 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-03-06T19:21:47.607Z,1741288907.607 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-03-06T19:21:47.608Z,1741288907.608 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-03-06T19:21:48.135Z,1741288908.135 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Mission Id="lab_test_optim">
    <DefineArg Name="MissionTimeout">
        <Units:minute />
        <Value>15</Value>
    </DefineArg>
    <DefineArg Name="RecordTime">
        <Units:minute />
        <Value>1</Value>
    </DefineArg>
    <DefineArg Name="BackseatWait">
        <Units:second />
        <Value>30</Value>
    </DefineArg>
    <DefineArg Name="UseMission">
        <True />
    </DefineArg>
    <DefineArg Name="UseHardcode">
        <False />
    </DefineArg>
    <DefineArg Name="InitialSampleTime">
        <Units:second />
        <Value>1</Value>
    </DefineArg>
    <DefineArg Name="SleepCycles">
        <Units:count />
        <Value>3</Value>
    </DefineArg>
    <DefineArg Name="LightMode">
        <Units:count />
        <Value>2</Value>
    </DefineArg>
    <DefineArg Name="BrightnessWhite">
        <Units:none_int />
        <Value>100</Value>
    </DefineArg>
    <DefineArg Name="BrightnessRed">
        <Units:none_int />
        <Value>100</Value>
    </DefineArg>
    <DefineOutput Name="CyclesWaited">
        <Units:count />
        <Value>0</Value>
    </DefineOutput>
    <DefineOutput Name="RecordingEnabled">
        <False />
    </DefineOutput>
    <DefineOutput Name="LightsEnabled">
        <False />
    </DefineOutput>
    <Timeout Duration="MissionTimeout" />
    <Insert Filename="Insert/BackseatDriver.tl" />
    <Assign>
        <Parallel />
        <Arg Name="BackseatDriver:EnableBackseat" />
        <True />
    </Assign>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="RecordingEnabled" />
        </While>
        <Sensor:PowerOnly.sampleLoad1 />
    </ReadData>
    <ReadData Strategy="MinError">
        <While>
            <Arg Name="LightsEnabled" />
        </While>
        <Sensor:MultiRay.lightModeLog />
    </ReadData>
    <Aggregate Id="Startup">
        <Sequence />
        <Syslog Severity="Important">
            Waiting 
            <Arg Name="BackseatWait" />
            <Units:second />
             for backseat to start up...
        </Syslog>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Arg Name="BackseatWait" />
            </Setting>
        </Guidance:Wait>
        <Aggregate Id="UseMission">
            <Sequence />
            <Break>
                <Not>
                    <Arg Name="UseMission" />
                </Not>
                <Or>
                    <Arg Name="UseHardcode" />
                </Or>
            </Break>
            <Assign>
                <Parallel />
                <Sensor:PowerOnly.sampleTime1 />
                <Arg Name="InitialSampleTime" />
            </Assign>
            <Assign>
                <Sequence />
                <Arg Name="RecordingEnabled" />
                <True />
            </Assign>
            <Syslog Severity="Important">
                Disabling Optim recording after 
                <Arg Name="InitialSampleTime" />
                <Units:second />
            </Syslog>
            <Assign>
                <Sequence />
                <Arg Name="RecordingEnabled" />
                <False />
            </Assign>
            <Guidance:Wait>
                <Sequence />
                <Setting>
                    <Guidance:Wait.duration />
                    <Arg Name="InitialSampleTime" />
                </Setting>
            </Guidance:Wait>
            <Assign>
                <Sequence />
                <Arg Name="RecordingEnabled" />
                <True />
            </Assign>
            <Syslog Severity="Important">Powering up Optim to try to tide over gap to handoff...</Syslog>
        </Aggregate>
        <Aggregate Id="UseBackdoor">
            <Sequence />
            <Break>
                <Arg Name="UseMission" />
                <Or>
                    <Arg Name="UseHardcode" />
                </Or>
            </Break>
            <Guidance:Execute>
                <Sequence />
                <Setting>
                    <Guidance:Execute.command />
                    <String>! echo 1 &gt; /dev/loadC3</String>
                </Setting>
            </Guidance:Execute>
            <Syslog Severity="Important">
                Optim power on. Spinning for 
                <Arg Name="SleepCycles" />
                <Units:count />
                 cycles.
            </Syslog>
            <Aggregate Id="WaitForStop">
                <Sequence Repeat="SleepCycles" />
                <Assign>
                    <Sequence />
                    <Arg Name="CyclesWaited" />
                    <Arg Name="CyclesWaited" />
                    <Add>
                        <Units:count />
                        <Value>1</Value>
                    </Add>
                </Assign>
            </Aggregate>
            <Guidance:Execute>
                <Sequence />
                <Setting>
                    <Guidance:Execute.command />
                    <String>! echo 0 &gt; /dev/loadC3</String>
                </Setting>
            </Guidance:Execute>
            <Syslog Severity="Important">Optim power off. Spinning again.</Syslog>
            <Aggregate Id="WaitForStart">
                <Sequence Repeat="SleepCycles" />
                <Assign>
                    <Sequence />
                    <Arg Name="CyclesWaited" />
                    <Arg Name="CyclesWaited" />
                    <Add>
                        <Units:count />
                        <Value>1</Value>
                    </Add>
                </Assign>
            </Aggregate>
            <Guidance:Execute>
                <Sequence />
                <Setting>
                    <Guidance:Execute.command />
                    <String>! echo 1 &gt; /dev/loadC3</String>
                </Setting>
            </Guidance:Execute>
            <Syslog Severity="Important">Optim power on. Handing off to mission.</Syslog>
        </Aggregate>
        <Aggregate Id="UseHardcode">
            <Sequence />
            <Break>
                <Not>
                    <Arg Name="UseHardcode" />
                </Not>
            </Break>
            <Guidance:Execute>
                <Sequence />
                <Setting>
                    <Guidance:Execute.command />
                    <String>! echo 1 &gt; /dev/loadC3; sleep 1; echo 0 &gt; /dev/loadC3; sleep 1; echo 1 &gt; dev/loadC3</String>
                </Setting>
            </Guidance:Execute>
            <Syslog Severity="Important">Hardcoded Optim command sent. Good luck.</Syslog>
        </Aggregate>
    </Aggregate>
    <Aggregate Id="Run">
        <Sequence />
        <Syslog Severity="Important">Trying to run Optim and Multiray forreal</Syslog>
        <Assign>
            <Sequence />
            <Arg Name="RecordingEnabled" />
            <True />
        </Assign>
        <Assign>
            <Sequence />
            <Arg Name="LightsEnabled" />
            <True />
        </Assign>
        <Assign>
            <Sequence />
            <Sensor:MultiRay.lightModeCommand />
            <Arg Name="LightMode" />
        </Assign>
        <Aggregate Id="setRed">
            <Sequence />
            <Break>
                <Arg Name="LightMode" />
                <Ne>
                    <Units:count />
                    <Value>1</Value>
                </Ne>
            </Break>
            <Assign>
                <Sequence />
                <Sensor:MultiRay.brightnessRed />
                <Arg Name="BrightnessRed" />
            </Assign>
            <Syslog Severity="Info">
                Setting multiray red brightness to
                <Arg Name="BrightnessRed" />
                <Units:count />
            </Syslog>
        </Aggregate>
        <Aggregate Id="setWhite">
            <Sequence />
            <Break>
                <Arg Name="LightMode" />
                <Ne>
                    <Units:count />
                    <Value>2</Value>
                </Ne>
            </Break>
            <Assign>
                <Sequence />
                <Sensor:MultiRay.brightnessWhite />
                <Arg Name="BrightnessWhite" />
            </Assign>
            <Syslog Severity="Info">
                Setting muliray white brightness to
                <Arg Name="BrightnessWhite" />
                <Units:count />
            </Syslog>
        </Aggregate>
        <Syslog Severity="Important">
            Recording for 
            <Arg Name="RecordTime" />
            <Units:minute />
        </Syslog>
        <Guidance:Wait>
            <Sequence />
            <Setting>
                <Guidance:Wait.duration />
                <Arg Name="RecordTime" />
            </Setting>
        </Guidance:Wait>
    </Aggregate>
    <Guidance:Wait>
        <Sequence />
        <Setting>
            <Guidance:Wait.duration />
            <Arg Name="MissionTimeout" />
        </Setting>
    </Guidance:Wait>
</Mission>

2025-03-06T19:21:48.143Z,1741288908.143 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-03-06T19:21:48.146Z,1741288908.146 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-03-06T19:21:48.148Z,1741288908.148 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-03-06T19:21:48.205Z,1741288908.205 [MissionManager](INFO): DefineArg lab_test_optim.UseMission = 1 bool
2025-03-06T19:21:48.207Z,1741288908.207 [MissionManager](INFO): DefineArg lab_test_optim.UseHardcode = 0 bool
2025-03-06T19:21:48.210Z,1741288908.210 [MissionManager](INFO): DefineArg lab_test_optim.InitialSampleTime = 1.000000 s
2025-03-06T19:21:48.213Z,1741288908.213 [MissionManager](INFO): DefineArg lab_test_optim.SleepCycles = 3.000000 count
2025-03-06T19:21:48.216Z,1741288908.216 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-03-06T19:21:48.219Z,1741288908.219 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-03-06T19:21:48.222Z,1741288908.222 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-03-06T19:21:48.225Z,1741288908.225 [MissionManager](INFO): DefineOutput lab_test_optim.CyclesWaited = 0.000000 count
2025-03-06T19:21:48.228Z,1741288908.228 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-03-06T19:21:48.231Z,1741288908.231 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-03-06T19:21:48.231Z,1741288908.231 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-03-06T19:21:48.232Z,1741288908.232 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-03-06T19:21:48.233Z,1741288908.233 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-03-06T19:21:48.251Z,1741288908.251 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
<?xml version="1.0" encoding="UTF-8" ?>
<!--generated by tl2xml-->
<Aggregate Id="BackseatDriver">
    <DefineArg Name="EnableBackseat">
        <False />
    </DefineArg>
    <Parallel />
    <Guidance:BackseatDriver>
        <Sequence />
        <Setting>
            <Guidance:BackseatDriver.powerBackseat />
            <Arg Name="EnableBackseat" />
        </Setting>
    </Guidance:BackseatDriver>
</Aggregate>

2025-03-06T19:21:48.288Z,1741288908.288 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-03-06T19:21:48.291Z,1741288908.291 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-03-06T19:21:48.335Z,1741288908.335 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T19:21:48.368Z,1741288908.368 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:48.394Z,1741288908.394 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:48.399Z,1741288908.399 [lab_test_optim:Startup:UseBackdoor:A.Execute](DEBUG): Construct Execute.
2025-03-06T19:21:48.421Z,1741288908.421 [lab_test_optim:Startup:UseBackdoor:D.Execute](DEBUG): Construct Execute.
2025-03-06T19:21:48.427Z,1741288908.427 [lab_test_optim:Startup:UseBackdoor:G.Execute](DEBUG): Construct Execute.
2025-03-06T19:21:48.462Z,1741288908.462 [lab_test_optim:Startup:UseHardcode:A.Execute](DEBUG): Construct Execute.
2025-03-06T19:21:48.526Z,1741288908.526 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:48.528Z,1741288908.528 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-03-06T19:21:48.553Z,1741288908.553 [MissionManager](DEBUG): 
#   Copyright (c) 2024 MBARI
#   MBARI Proprietary Information. Confidential. All Rights Reserved
#   Unauthorized copying or distribution of this file via any medium is strictly
#   prohibited.
#
#   WARNING - This file contains information whose export is restricted by the
#   Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
#   amended. Violations of these export laws are subject to severe civil and/or
#   criminal penalties.

mission lab_test_optim {
  arguments {
    MissionTimeout = 15 minute
      """
      Backseat will stay on for this duration, independent of Optim state
      """

    RecordTime = 1 minute
      """
      How long to record after startup sequence (hopefully) turns on Optim camera
      """

    BackseatWait = 30 second
      """
      How long to wait for the backseat to power up before attempting to power the Optim
      """

    UseMission = true
      """
      If true, tries to go through the application and use components/behaviors for commands.
      Set InitialSampleTime to change delays. If false, backdoors app. Use SleepCycles to change delays.
      Optim must be on C3.
      """

    UseHardcode = false
      """
      If true, backdoors app with a powercycle and a hardcoded sleep 1. Try the two other modes first?
      Optim must be on C3.
      """

    InitialSampleTime = 1 second
      """
      PowerOnly sample time for initial record. Will go back to continuous after startup.
      """

    SleepCycles = 3 count
      """
      How many vehicle computation cycles to wait before commanding the Optim off on initial record
      """

    LightMode = 2 count
      """
      Mode for Multiray lights. 0 is off, 1 is red, 2 is white
      """

    BrightnessWhite = 100 none_int
      """
      White Multiray LED brightness, 0-100
      """

    BrightnessRed = 100 none_int
      """
      Red Multiray LED brightness, 0-100
      """
  }

  output {
    CyclesWaited = 0 count

    RecordingEnabled = false

    LightsEnabled = false
  }

  timeout duration=MissionTimeout

  insert Insert/BackseatDriver.tl
  assign in parallel BackseatDriver:EnableBackseat = true

  readData strategy="MinError" {
    while ( RecordingEnabled )

    Sensor:PowerOnly.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 UseMission {
      run in sequence

      break if (
        not UseMission
        or UseHardcode
      )

      assign in parallel Sensor:PowerOnly.sampleTime1 = InitialSampleTime

      assign in sequence RecordingEnabled = true

      syslog important "Disabling Optim recording after " + InitialSampleTime~s
      assign in sequence RecordingEnabled = false

      behavior Guidance:Wait {
        run in sequence

        set duration = InitialSampleTime
      }

      assign in sequence RecordingEnabled = true
      syslog important "Powering up Optim to try to tide over gap to handoff..."
    }

    aggregate UseBackdoor {
      run in sequence

      break if (
        UseMission
        or UseHardcode
      )

      behavior Guidance:Execute {
        run in sequence

        set command = "! echo 1 > /dev/loadC3"
      }

      syslog important "Optim power on. Spinning for " + SleepCycles~count + " cycles."

      aggregate WaitForStop {
        run in sequence repeat=SleepCycles

        assign in sequence CyclesWaited = CyclesWaited + 1 count
      }

      behavior Guidance:Execute {
        run in sequence

        set command = "! echo 0 > /dev/loadC3"
      }

      syslog important "Optim power off. Spinning again."

      aggregate WaitForStart {
        run in sequence repeat=SleepCycles

        assign in sequence CyclesWaited = CyclesWaited + 1 count
      }

      behavior Guidance:Execute {
        run in sequence

        set command = "! echo 1 > /dev/loadC3"
      }

      syslog important "Optim power on. Handing off to mission."
    }

    aggregate UseHardcode {
      run in sequence

      break if ( not UseHardcode )

      behavior Guidance:Execute {
        run in sequence

        set command = "! echo 1 > /dev/loadC3; sleep 1; echo 0 > /dev/loadC3; sleep 1; echo 1 > dev/loadC3"
      }

      syslog important "Hardcoded Optim command sent. Good luck."
    }
  }

  aggregate Run {
    run in sequence

    syslog important "Trying to run Optim and Multiray forreal"

    assign in sequence RecordingEnabled = true
    assign in sequence LightsEnabled = true
    assign in sequence Sensor:MultiRay.lightModeCommand = LightMode

    aggregate setRed {
      run in sequence

      break if ( LightMode != 1 count )

      assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
      syslog info "Setting multiray red brightness to" + BrightnessRed~count
    }

    aggregate setWhite {
      run in sequence

      break if ( LightMode != 2 count )

      assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
      syslog info "Setting muliray white brightness to" + BrightnessWhite~count
    }

    syslog important "Recording for " + RecordTime~min

    behavior Guidance:Wait {
      run in sequence

      set duration = RecordTime
    }
  }

  behavior Guidance:Wait {
    run in sequence

    set duration = MissionTimeout
  }
}


2025-03-06T19:21:48.571Z,1741288908.571 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-03-06T19:21:48.748Z,1741288908.748 [Default] Stopped
2025-03-06T19:21:48.748Z,1741288908.748 [Default](DEBUG): Aggregate::uninitialize Default
2025-03-06T19:21:48.748Z,1741288908.748 [Default:B.GoToSurface] Stopped
2025-03-06T19:21:48.748Z,1741288908.748 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-03-06T19:21:48.748Z,1741288908.748 [Default:CheckIn] Stopped
2025-03-06T19:21:48.748Z,1741288908.748 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-03-06T19:21:48.749Z,1741288908.749 [Default:CheckIn:Read_GPS] Stopped
2025-03-06T19:21:48.749Z,1741288908.749 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-03-06T19:21:48.749Z,1741288908.749 [lab_test_optim] Running Loop=1
2025-03-06T19:21:48.753Z,1741288908.753 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-03-06T19:21:48.753Z,1741288908.753 [lab_test_optim:BackseatDriver] Running Loop=1
2025-03-06T19:21:48.753Z,1741288908.753 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-03-06T19:21:48.754Z,1741288908.754 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-03-06T19:21:48.754Z,1741288908.754 [lab_test_optim:B] Running Loop=1
2025-03-06T19:21:48.754Z,1741288908.754 [lab_test_optim:C] Running Loop=1
2025-03-06T19:21:48.754Z,1741288908.754 [lab_test_optim:D] Running Loop=1
2025-03-06T19:21:48.754Z,1741288908.754 [lab_test_optim:Startup] Running Loop=1
2025-03-06T19:21:48.754Z,1741288908.754 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-03-06T19:21:48.754Z,1741288908.754 [lab_test_optim:Startup:A] Running Loop=1
2025-03-06T19:21:48.755Z,1741288908.755 [lab_test_optim:Startup:A](IMPORTANT): Waiting  30.000000 s  for backseat to start up...
2025-03-06T19:21:48.755Z,1741288908.755 [lab_test_optim:Startup:A] Stopped
2025-03-06T19:21:48.755Z,1741288908.755 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-03-06T19:21:48.755Z,1741288908.755 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:21:48.755Z,1741288908.755 [lab_test_optim:D] Stopped
2025-03-06T19:21:48.755Z,1741288908.755 [lab_test_optim:C] Stopped
2025-03-06T19:21:48.755Z,1741288908.755 [lab_test_optim:B] Running Loop=1
2025-03-06T19:21:48.756Z,1741288908.756 [lab_test_optim:BackseatDriver] Running Loop=1
2025-03-06T19:21:48.756Z,1741288908.756 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-03-06T19:21:48.930Z,1741288908.930 [BackseatComponent](INFO): Powering up
2025-03-06T19:21:48.930Z,1741288908.930 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-03-06T19:21:49.123Z,1741288909.123 [Power24vConverter](INFO): Powering up.
2025-03-06T19:22:07.328Z,1741288927.328 [Reporter](INFO): BackseatComponent.component_avgCurrent 0.000000 mA
2025-03-06T19:22:10.187Z,1741288930.187 [Reporter](INFO): BackseatComponent.component_avgCurrent 7.340000 mA
2025-03-06T19:22:19.436Z,1741288939.436 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-03-06T19:22:19.437Z,1741288939.437 [lab_test_optim:Startup:B.Wait] Stopped
2025-03-06T19:22:19.437Z,1741288939.437 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:22:19.437Z,1741288939.437 [lab_test_optim:Startup:UseMission] Running Loop=1
2025-03-06T19:22:19.437Z,1741288939.437 [lab_test_optim:Startup:UseMission](DEBUG): Aggregate::initialize lab_test_optim:Startup:UseMission
2025-03-06T19:22:19.437Z,1741288939.437 [lab_test_optim:Startup:UseMission:A] Running Loop=1
2025-03-06T19:22:19.453Z,1741288939.453 [lab_test_optim:Startup:UseMission:B] Running Loop=1
2025-03-06T19:22:19.838Z,1741288939.838 [lab_test_optim:Startup:UseMission:B] Stopped
2025-03-06T19:22:19.838Z,1741288939.838 [lab_test_optim:Startup:UseMission:C] Running Loop=1
2025-03-06T19:22:19.838Z,1741288939.838 [lab_test_optim:Startup:UseMission:A] Running Loop=1
2025-03-06T19:22:20.246Z,1741288940.246 [lab_test_optim:Startup:UseMission:C](IMPORTANT): Disabling Optim recording after  1.000000 s 
2025-03-06T19:22:20.246Z,1741288940.246 [lab_test_optim:Startup:UseMission:C] Stopped
2025-03-06T19:22:20.246Z,1741288940.246 [lab_test_optim:Startup:UseMission:D] Running Loop=1
2025-03-06T19:22:20.246Z,1741288940.246 [lab_test_optim:C] Running Loop=1
2025-03-06T19:22:20.247Z,1741288940.247 [lab_test_optim:C] Running Loop=1
2025-03-06T19:22:20.247Z,1741288940.247 [lab_test_optim:C](CRITICAL): Unable to read non-existent URI:PowerOnly.sampleLoad1
2025-03-06T19:22:20.247Z,1741288940.247 [lab_test_optim:C](CRITICAL): Unable to read non-existent data element: PowerOnly.sampleLoad1
2025-03-06T19:22:20.255Z,1741288940.255 [CommandExec](FAULT): Scheduling is paused
2025-03-06T19:22:20.256Z,1741288940.256 [CBIT](INFO): Critical error at 20250306T192220
2025-03-06T19:22:20.258Z,1741288940.258 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-03-06T19:22:20.672Z,1741288940.672 [lab_test_optim:Startup:UseMission:D] Stopped
2025-03-06T19:22:20.672Z,1741288940.672 [lab_test_optim:Startup:UseMission:E.Wait] Running Loop=1
2025-03-06T19:22:20.673Z,1741288940.673 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:22:20.673Z,1741288940.673 [lab_test_optim:C](CRITICAL): Unable to read non-existent URI:PowerOnly.sampleLoad1
2025-03-06T19:22:20.673Z,1741288940.673 [lab_test_optim:C](CRITICAL): Unable to read non-existent data element: PowerOnly.sampleLoad1
2025-03-06T19:22:20.677Z,1741288940.677 [MissionManager](INFO): MissionManager is completed.
2025-03-06T19:22:20.678Z,1741288940.678 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim] Stopped
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:BackseatDriver] Stopped
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:B] Stopped
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:C] Stopped
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:Startup] Stopped
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:Startup:UseMission] Stopped
2025-03-06T19:22:20.678Z,1741288940.678 [lab_test_optim:Startup:UseMission](DEBUG): Aggregate::uninitialize lab_test_optim:Startup:UseMission
2025-03-06T19:22:20.679Z,1741288940.679 [lab_test_optim:Startup:UseMission:A] Stopped
2025-03-06T19:22:20.679Z,1741288940.679 [lab_test_optim:Startup:UseMission:E.Wait] Stopped
2025-03-06T19:22:20.679Z,1741288940.679 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:22:20.701Z,1741288940.701 [CBIT](INFO): Critical error at 20250306T192220
2025-03-06T19:22:21.072Z,1741288941.072 [MissionManager](IMPORTANT): Started mission Default
2025-03-06T19:22:21.073Z,1741288941.073 [Default] Running Loop=1
2025-03-06T19:22:21.073Z,1741288941.073 [Default](DEBUG): Aggregate::initialize Default
2025-03-06T19:22:21.073Z,1741288941.073 [Default:B.GoToSurface] Running Loop=1
2025-03-06T19:22:21.073Z,1741288941.073 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-03-06T19:22:21.074Z,1741288941.074 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-03-06T19:22:21.074Z,1741288941.074 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-03-06T19:22:21.074Z,1741288941.074 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-03-06T19:22:21.075Z,1741288941.075 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-03-06T19:22:21.075Z,1741288941.075 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-03-06T19:22:21.075Z,1741288941.075 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-03-06T19:22:21.076Z,1741288941.076 [Default:A.Wait] Running Loop=1
2025-03-06T19:22:21.076Z,1741288941.076 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-03-06T19:22:22.327Z,1741288942.327 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-03-06T19:22:22.327Z,1741288942.327 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-03-06T19:22:22.407Z,1741288942.407 [Reporter](INFO): BackseatComponent.handled_message 0 bool
2025-03-06T19:22:22.407Z,1741288942.407 [Reporter](INFO): BackseatComponent.component_avgCurrent 7.340000 mA
2025-03-06T19:22:34.390Z,1741288954.390 [Default:A.Wait](INFO): Done Waiting.
2025-03-06T19:22:34.390Z,1741288954.390 [Default:A.Wait] Stopped
2025-03-06T19:22:34.390Z,1741288954.390 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-03-06T19:22:34.786Z,1741288954.786 [Default:CheckIn] Running Loop=1
2025-03-06T19:22:34.786Z,1741288954.786 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-03-06T19:22:34.786Z,1741288954.786 [Default:CheckIn:Read_GPS] Running Loop=1
2025-03-06T19:22:40.518Z,1741288960.518 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-03-06T19:22:40.518Z,1741288960.518 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-03-06T19:22:40.519Z,1741288960.519 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-03-06T19:22:41.514Z,1741288961.514 [CommandExec](IMPORTANT): got command configSet list
2025-03-06T19:22:41.514Z,1741288961.514 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-03-06T19:22:41.515Z,1741288961.515 [CommandExec](IMPORTANT): DAT.loadAtStartup=0 bool;

2025-03-06T19:22:41.516Z,1741288961.516 [CommandExec](IMPORTANT): DATMMP.loadAtStartup=1 bool;

2025-03-06T19:22:41.516Z,1741288961.516 [CommandExec](IMPORTANT): DATMMP.simulateHardware=0 bool;

2025-03-06T19:22:41.517Z,1741288961.517 [CommandExec](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;

2025-03-06T19:22:41.522Z,1741288961.522 [CommandExec](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;

2025-03-06T19:22:41.523Z,1741288961.523 [CommandExec](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;

2025-03-06T19:22:41.523Z,1741288961.523 [CommandExec](IMPORTANT): MultiRay.loadAtStartup=1 bool;

2025-03-06T19:22:41.524Z,1741288961.524 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=185.902950 cubic_centimeter;

2025-03-06T19:22:41.525Z,1741288961.525 [CommandExec](IMPORTANT): VerticalControl.massDefault=13