2022-11-08T20:01:20.987Z,1667937680.987 [Supervisor](DEBUG): Initializing supervisor. 2022-11-08T20:01:20.991Z,1667937680.991 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2022-11-08T20:01:20.991Z,1667937680.991 [SyncHandler](INFO): Protected caller Thread ID is 837 2022-11-08T20:01:20.992Z,1667937680.992 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2022-11-08T20:01:20.993Z,1667937680.993 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2022-11-08T20:01:20.993Z,1667937680.993 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838 2022-11-08T20:01:20.997Z,1667937680.997 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2022-11-08T20:01:21.014Z,1667937681.014 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2022-11-08T20:01:21.015Z,1667937681.015 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2022-11-08T20:01:21.016Z,1667937681.016 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839 2022-11-08T20:01:21.020Z,1667937681.020 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2022-11-08T20:01:21.021Z,1667937681.021 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2022-11-08T20:01:21.021Z,1667937681.021 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840 2022-11-08T20:01:21.023Z,1667937681.023 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2022-11-08T20:01:21.024Z,1667937681.024 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2022-11-08T20:01:21.025Z,1667937681.025 [logger ThreadHandler](INFO): Protected caller Thread ID is 841 2022-11-08T20:01:21.028Z,1667937681.028 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2022-11-08T20:01:21.029Z,1667937681.029 [Supervisor](INFO): Looking for Config files in directory: Config/ 2022-11-08T20:01:21.033Z,1667937681.033 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2022-11-08T20:01:21.459Z,1667937681.459 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2022-11-08T20:01:21.461Z,1667937681.461 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2022-11-08T20:01:21.676Z,1667937681.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2022-11-08T20:01:21.677Z,1667937681.677 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2022-11-08T20:01:21.860Z,1667937681.860 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2022-11-08T20:01:21.861Z,1667937681.861 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2022-11-08T20:01:21.967Z,1667937681.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2022-11-08T20:01:21.968Z,1667937681.968 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2022-11-08T20:01:22.336Z,1667937682.336 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2022-11-08T20:01:22.338Z,1667937682.338 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2022-11-08T20:01:22.658Z,1667937682.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2022-11-08T20:01:22.660Z,1667937682.660 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2022-11-08T20:01:22.756Z,1667937682.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2022-11-08T20:01:22.758Z,1667937682.758 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2022-11-08T20:01:22.976Z,1667937682.976 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2022-11-08T20:01:22.978Z,1667937682.978 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2022-11-08T20:01:23.487Z,1667937683.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2022-11-08T20:01:23.488Z,1667937683.488 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2022-11-08T20:01:23.840Z,1667937683.840 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2022-11-08T20:01:23.840Z,1667937683.840 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2022-11-08T20:01:23.921Z,1667937683.921 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2022-11-08T20:01:24.131Z,1667937684.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2022-11-08T20:01:24.131Z,1667937684.131 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2022-11-08T20:01:24.267Z,1667937684.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2022-11-08T20:01:24.268Z,1667937684.268 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2022-11-08T20:01:25.710Z,1667937685.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2022-11-08T20:01:25.711Z,1667937685.711 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2022-11-08T20:01:25.791Z,1667937685.791 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2022-11-08T20:01:26.087Z,1667937686.087 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2022-11-08T20:01:26.089Z,1667937686.089 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/ 2022-11-08T20:01:26.092Z,1667937686.092 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg 2022-11-08T20:01:26.271Z,1667937686.271 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg 2022-11-08T20:01:26.364Z,1667937686.364 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg 2022-11-08T20:01:26.477Z,1667937686.477 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg 2022-11-08T20:01:26.578Z,1667937686.578 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg 2022-11-08T20:01:26.661Z,1667937686.661 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg 2022-11-08T20:01:26.746Z,1667937686.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg 2022-11-08T20:01:26.861Z,1667937686.861 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg 2022-11-08T20:01:26.959Z,1667937686.959 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg 2022-11-08T20:01:27.122Z,1667937687.122 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg 2022-11-08T20:01:27.385Z,1667937687.385 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2022-11-08T20:01:27.386Z,1667937687.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg 2022-11-08T20:01:27.480Z,1667937687.480 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2022-11-08T20:01:27.498Z,1667937687.498 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2022-11-08T20:01:27.855Z,1667937687.855 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2022-11-08T20:01:27.856Z,1667937687.856 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2022-11-08T20:01:27.993Z,1667937687.993 [DeadReckonUsingMultipleVelocitySources] Loaded 2022-11-08T20:01:27.994Z,1667937687.994 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2022-11-08T20:01:28.033Z,1667937688.033 [DeadReckonUsingSpeedCalculator] Loaded 2022-11-08T20:01:28.033Z,1667937688.033 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2022-11-08T20:01:28.046Z,1667937688.046 [NavChart] Loaded 2022-11-08T20:01:28.047Z,1667937688.047 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2022-11-08T20:01:28.052Z,1667937688.052 [UniversalFixResidualReporter] Loaded 2022-11-08T20:01:28.052Z,1667937688.052 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2022-11-08T20:01:28.053Z,1667937688.053 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2022-11-08T20:01:28.053Z,1667937688.053 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2022-11-08T20:01:28.069Z,1667937688.069 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2022-11-08T20:01:28.070Z,1667937688.070 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2022-11-08T20:01:28.272Z,1667937688.272 [PAR_Licor] Loaded 2022-11-08T20:01:28.272Z,1667937688.272 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2022-11-08T20:01:28.304Z,1667937688.304 [WetLabsBB2FL] Loaded 2022-11-08T20:01:28.304Z,1667937688.304 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2022-11-08T20:01:28.305Z,1667937688.305 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065A4E0 2022-11-08T20:01:28.306Z,1667937688.306 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 923 2022-11-08T20:01:28.306Z,1667937688.306 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2022-11-08T20:01:28.308Z,1667937688.308 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2022-11-08T20:01:28.375Z,1667937688.375 [VerticalControl](DEBUG): Construct VerticalControl. 2022-11-08T20:01:28.436Z,1667937688.436 [VerticalControl] Loaded 2022-11-08T20:01:28.436Z,1667937688.436 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2022-11-08T20:01:28.439Z,1667937688.439 [HorizontalControl](DEBUG): Construct HorizontalControl. 2022-11-08T20:01:28.481Z,1667937688.481 [HorizontalControl] Loaded 2022-11-08T20:01:28.482Z,1667937688.482 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2022-11-08T20:01:28.484Z,1667937688.484 [SpeedControl](DEBUG): Construct SpeedControl. 2022-11-08T20:01:28.487Z,1667937688.487 [SpeedControl] Loaded 2022-11-08T20:01:28.487Z,1667937688.487 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2022-11-08T20:01:28.490Z,1667937688.490 [LoopControl](DEBUG): Construct LoopControl. 2022-11-08T20:01:28.491Z,1667937688.491 [LoopControl] Loaded 2022-11-08T20:01:28.491Z,1667937688.491 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2022-11-08T20:01:28.491Z,1667937688.491 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2022-11-08T20:01:28.492Z,1667937688.492 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2022-11-08T20:01:28.561Z,1667937688.561 [DepthRateCalculator] Loaded 2022-11-08T20:01:28.561Z,1667937688.561 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2022-11-08T20:01:28.566Z,1667937688.566 [PitchRateCalculator] Loaded 2022-11-08T20:01:28.566Z,1667937688.566 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2022-11-08T20:01:28.575Z,1667937688.575 [SpeedCalculator] Loaded 2022-11-08T20:01:28.576Z,1667937688.576 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2022-11-08T20:01:28.580Z,1667937688.580 [YawRateCalculator] Loaded 2022-11-08T20:01:28.580Z,1667937688.580 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2022-11-08T20:01:28.598Z,1667937688.598 [ElevatorOffsetCalculator] Loaded 2022-11-08T20:01:28.599Z,1667937688.599 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2022-11-08T20:01:28.599Z,1667937688.599 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2022-11-08T20:01:28.600Z,1667937688.600 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2022-11-08T20:01:28.716Z,1667937688.716 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2022-11-08T20:01:28.716Z,1667937688.716 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2022-11-08T20:01:28.799Z,1667937688.799 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2022-11-08T20:01:28.800Z,1667937688.800 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2022-11-08T20:01:28.949Z,1667937688.949 [BuoyancyServo] Loaded 2022-11-08T20:01:28.949Z,1667937688.949 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2022-11-08T20:01:28.969Z,1667937688.969 [ElevatorServo] Loaded 2022-11-08T20:01:28.969Z,1667937688.969 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2022-11-08T20:01:28.989Z,1667937688.989 [MassServo] Loaded 2022-11-08T20:01:28.989Z,1667937688.989 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2022-11-08T20:01:29.007Z,1667937689.007 [RudderServo] Loaded 2022-11-08T20:01:29.008Z,1667937689.008 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2022-11-08T20:01:29.022Z,1667937689.022 [ThrusterHE] Loaded 2022-11-08T20:01:29.022Z,1667937689.022 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2022-11-08T20:01:29.023Z,1667937689.023 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2022-11-08T20:01:29.023Z,1667937689.023 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2022-11-08T20:01:29.207Z,1667937689.207 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2022-11-08T20:01:29.207Z,1667937689.207 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2022-11-08T20:01:29.918Z,1667937689.918 [AHRS_M2] Loaded 2022-11-08T20:01:29.918Z,1667937689.918 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2022-11-08T20:01:30.167Z,1667937690.167 [BackseatComponent] Loaded 2022-11-08T20:01:30.168Z,1667937690.168 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2022-11-08T20:01:30.169Z,1667937690.169 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0 2022-11-08T20:01:30.169Z,1667937690.169 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 924 2022-11-08T20:01:30.172Z,1667937690.172 [LcmUniversalReporter] Loaded 2022-11-08T20:01:30.172Z,1667937690.172 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2022-11-08T20:01:31.396Z,1667937691.396 [BPC1] Loaded 2022-11-08T20:01:31.397Z,1667937691.397 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2022-11-08T20:01:31.538Z,1667937691.538 [DataOverHttps] Loaded 2022-11-08T20:01:31.538Z,1667937691.538 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2022-11-08T20:01:31.539Z,1667937691.539 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0 2022-11-08T20:01:31.540Z,1667937691.540 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925 2022-11-08T20:01:31.561Z,1667937691.561 [Depth_Keller] Loaded 2022-11-08T20:01:31.561Z,1667937691.561 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2022-11-08T20:01:31.566Z,1667937691.566 [DropWeight] Loaded 2022-11-08T20:01:31.566Z,1667937691.566 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2022-11-08T20:01:31.584Z,1667937691.584 [MultiRay] Loaded 2022-11-08T20:01:31.584Z,1667937691.584 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2022-11-08T20:01:31.646Z,1667937691.646 [NAL9602] Loaded 2022-11-08T20:01:31.646Z,1667937691.646 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2022-11-08T20:01:31.676Z,1667937691.676 [Onboard] Loaded 2022-11-08T20:01:31.677Z,1667937691.677 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2022-11-08T20:01:31.678Z,1667937691.678 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0 2022-11-08T20:01:31.678Z,1667937691.678 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926 2022-11-08T20:01:31.684Z,1667937691.684 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3 2022-11-08T20:01:31.695Z,1667937691.695 [PowerOnly] Loaded 2022-11-08T20:01:31.695Z,1667937691.695 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2022-11-08T20:01:31.707Z,1667937691.707 [Power24vConverter] Loaded 2022-11-08T20:01:31.707Z,1667937691.707 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2022-11-08T20:01:31.721Z,1667937691.721 [Radio_Surface] Loaded 2022-11-08T20:01:31.721Z,1667937691.721 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2022-11-08T20:01:31.722Z,1667937691.722 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0 2022-11-08T20:01:31.722Z,1667937691.722 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927 2022-11-08T20:01:31.817Z,1667937691.817 [DAT] Loaded 2022-11-08T20:01:31.817Z,1667937691.817 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2022-11-08T20:01:31.818Z,1667937691.818 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B154E0 2022-11-08T20:01:31.819Z,1667937691.819 [DAT ThreadHandler](INFO): Protected caller Thread ID is 928 2022-11-08T20:01:31.819Z,1667937691.819 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2022-11-08T20:01:31.820Z,1667937691.820 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2022-11-08T20:01:31.989Z,1667937691.989 [SBIT](DEBUG): Construct Startup Built In Test. 2022-11-08T20:01:31.998Z,1667937691.998 [SBIT] Loaded 2022-11-08T20:01:31.998Z,1667937691.998 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2022-11-08T20:01:32.001Z,1667937692.001 [IBIT](DEBUG): Construct Initiated Built In Test. 2022-11-08T20:01:32.015Z,1667937692.015 [IBIT] Loaded 2022-11-08T20:01:32.015Z,1667937692.015 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2022-11-08T20:01:32.021Z,1667937692.021 [CBIT](DEBUG): Construct Continuous Built In Test. 2022-11-08T20:01:32.125Z,1667937692.125 [CBIT] Loaded 2022-11-08T20:01:32.125Z,1667937692.125 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2022-11-08T20:01:32.125Z,1667937692.125 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2022-11-08T20:01:32.126Z,1667937692.126 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2022-11-08T20:01:32.168Z,1667937692.168 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2022-11-08T20:01:32.174Z,1667937692.174 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2022-11-08T20:01:32.177Z,1667937692.177 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2022-11-08T20:01:32.189Z,1667937692.189 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2022-11-08T20:01:32.190Z,1667937692.190 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA34E0 2022-11-08T20:01:32.190Z,1667937692.190 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929 2022-11-08T20:01:32.194Z,1667937692.194 [Supervisor](INFO): Main Thread ID is 832 2022-11-08T20:01:32.194Z,1667937692.194 [Supervisor](DEBUG): Running supervisor. 2022-11-08T20:01:32.195Z,1667937692.195 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930 2022-11-08T20:01:32.195Z,1667937692.195 [CommandExec](INFO): Initializing the command executive. 2022-11-08T20:01:32.197Z,1667937692.197 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931 2022-11-08T20:01:32.199Z,1667937692.199 [controlThread ThreadHandler](INFO): Handler Thread ID is 932 2022-11-08T20:01:32.199Z,1667937692.199 [controlThread](DEBUG): Initializing ControlThread 2022-11-08T20:01:32.201Z,1667937692.201 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T20:01:32.201Z,1667937692.201 [NavChart](DEBUG): Initialize NavChart Navigation. 2022-11-08T20:01:32.202Z,1667937692.202 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2022-11-08T20:01:32.204Z,1667937692.204 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2022-11-08T20:01:32.206Z,1667937692.206 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2022-11-08T20:01:32.207Z,1667937692.207 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2022-11-08T20:01:32.207Z,1667937692.207 [LoopControl](DEBUG): Initialize LoopControlComponent. 2022-11-08T20:01:32.207Z,1667937692.207 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2022-11-08T20:01:32.208Z,1667937692.208 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2022-11-08T20:01:32.208Z,1667937692.208 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2022-11-08T20:01:32.208Z,1667937692.208 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2022-11-08T20:01:32.209Z,1667937692.209 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2022-11-08T20:01:32.215Z,1667937692.215 [SBIT](INFO): Initialize SBIT Component. 2022-11-08T20:01:32.215Z,1667937692.215 [SBIT](IMPORTANT): git: 2022-10-11-45-gb822ed017 2022-11-08T20:01:32.215Z,1667937692.215 [SBIT](INFO): git hash: b822ed017b998e9f5c0380c5dda45bcbd9b57e7d 2022-11-08T20:01:32.216Z,1667937692.216 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2022-11-08T20:01:32.217Z,1667937692.217 [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 2022-11-08T20:01:32.218Z,1667937692.218 [SBIT](INFO): Beginning SBIT in 109.000000 seconds. 2022-11-08T20:01:32.218Z,1667937692.218 [IBIT](INFO): Initialize IBIT Component. 2022-11-08T20:01:32.219Z,1667937692.219 [CBIT](DEBUG): Initialize CBIT Component. 2022-11-08T20:01:32.220Z,1667937692.220 [logger ThreadHandler](INFO): Handler Thread ID is 933 2022-11-08T20:01:32.232Z,1667937692.232 [CBIT](DEBUG): Initialized mux pins. 2022-11-08T20:01:32.232Z,1667937692.232 [CBIT](DEBUG): Initializing the watchdog timer. 2022-11-08T20:01:32.240Z,1667937692.240 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 934 2022-11-08T20:01:32.245Z,1667937692.245 [WetLabsBB2FL](INFO): Powering up 2022-11-08T20:01:32.246Z,1667937692.246 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 936 2022-11-08T20:01:32.252Z,1667937692.252 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 937 2022-11-08T20:01:32.253Z,1667937692.253 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2022-11-08T20:01:32.256Z,1667937692.256 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2022-11-08T20:01:32.257Z,1667937692.257 [CBIT](DEBUG): Initializing heartbeat. 2022-11-08T20:01:32.264Z,1667937692.264 [Onboard ThreadHandler](INFO): Handler Thread ID is 938 2022-11-08T20:01:32.282Z,1667937692.282 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 939 2022-11-08T20:01:32.304Z,1667937692.304 [DAT ThreadHandler](INFO): Handler Thread ID is 940 2022-11-08T20:01:32.305Z,1667937692.305 [DAT](INFO): Powering up 2022-11-08T20:01:32.305Z,1667937692.305 [DAT](DEBUG): Initializing DAT. 2022-11-08T20:01:32.309Z,1667937692.309 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 942 2022-11-08T20:01:32.317Z,1667937692.317 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2022-11-08T20:01:32.317Z,1667937692.317 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2022-11-08T20:01:32.318Z,1667937692.318 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2022-11-08T20:01:32.318Z,1667937692.318 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2022-11-08T20:01:32.318Z,1667937692.318 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2022-11-08T20:01:32.318Z,1667937692.318 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2022-11-08T20:01:32.318Z,1667937692.318 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2022-11-08T20:01:32.318Z,1667937692.318 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2022-11-08T20:01:32.328Z,1667937692.328 [CBIT](DEBUG): Deactivating GF circuits. 2022-11-08T20:01:32.329Z,1667937692.329 [CBIT](DEBUG): Deactivating emergency mode. 2022-11-08T20:01:32.364Z,1667937692.364 [CBIT](DEBUG): Backplane powered. 2022-11-08T20:01:32.365Z,1667937692.365 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2022-11-08T20:01:32.424Z,1667937692.424 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-08T20:01:32.436Z,1667937692.436 [MissionManager](DEBUG): 2022-11-08T20:01:32.436Z,1667937692.436 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2022-11-08T20:01:32.523Z,1667937692.523 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2022-11-08T20:01:32.525Z,1667937692.525 [Default:A.Wait](DEBUG): Construct Wait. 2022-11-08T20:01:32.527Z,1667937692.527 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-08T20:01:32.579Z,1667937692.579 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2022-11-08T20:01:32.581Z,1667937692.581 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2022-11-08T20:01:32.599Z,1667937692.599 [Default:E.Execute](DEBUG): Construct Execute. 2022-11-08T20:01:32.603Z,1667937692.603 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2022-11-08T20:01:32.613Z,1667937692.613 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2022-11-08T20:01:32.626Z,1667937692.626 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2022-11-08T20:01:32.688Z,1667937692.688 [Radio_Surface](INFO): Powering up 2022-11-08T20:01:32.802Z,1667937692.802 [MultiRay](INFO): Powering up MultiRay Lights 2022-11-08T20:01:32.833Z,1667937692.833 [Power24vConverter](INFO): Powering up. 2022-11-08T20:01:32.864Z,1667937692.864 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2022-11-08T20:01:32.872Z,1667937692.872 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2022-11-08T20:01:32.873Z,1667937692.873 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-11-08T20:01:32.880Z,1667937692.880 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-11-08T20:01:32.881Z,1667937692.881 [MassServo](DEBUG): Initializing EZServoServo. 2022-11-08T20:01:32.888Z,1667937692.888 [MassServo](DEBUG): Initializing MassServo. 2022-11-08T20:01:32.890Z,1667937692.890 [RudderServo](DEBUG): Initializing EZServoServo. 2022-11-08T20:01:32.897Z,1667937692.897 [RudderServo](DEBUG): Initializing RudderServo. 2022-11-08T20:01:32.898Z,1667937692.898 [ThrusterHE](DEBUG): Initializing EZServoServo. 2022-11-08T20:01:32.904Z,1667937692.904 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2022-11-08T20:01:33.089Z,1667937693.089 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-11-08T20:01:33.089Z,1667937693.089 [DropWeight] Hardware Fault, FailCount= 1 2022-11-08T20:01:33.089Z,1667937693.089 [DropWeight](ERROR): Hardware Fault 2022-11-08T20:01:33.116Z,1667937693.116 [MultiRay](IMPORTANT): All lights off 2022-11-08T20:01:33.158Z,1667937693.158 [CommandExec](FAULT): Scheduling is paused 2022-11-08T20:01:33.159Z,1667937693.159 [CBIT](INFO): Critical error at 20221108T200133 2022-11-08T20:01:33.159Z,1667937693.159 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-11-08T20:01:33.169Z,1667937693.169 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-11-08T20:01:33.170Z,1667937693.170 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-11-08T20:01:33.760Z,1667937693.760 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2022-11-08T20:01:33.760Z,1667937693.760 [RudderServo](FAULT): Rudder failed to initialize 2022-11-08T20:01:33.760Z,1667937693.760 [RudderServo] Communications Fault, FailCount= 1 2022-11-08T20:01:33.760Z,1667937693.760 [RudderServo](ERROR): Communications Fault 2022-11-08T20:01:33.762Z,1667937693.762 [CBIT](INFO): Critical error at 20221108T200133 2022-11-08T20:01:33.765Z,1667937693.765 [CBIT](ERROR): Communications Fault in component: RudderServo 2022-11-08T20:01:33.997Z,1667937693.997 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-11-08T20:01:33.997Z,1667937693.997 [RudderServo](INFO): Powering down 2022-11-08T20:01:34.661Z,1667937694.661 [RudderServo](DEBUG): Initializing EZServoServo. 2022-11-08T20:01:34.781Z,1667937694.781 [RudderServo](DEBUG): Initializing RudderServo. 2022-11-08T20:01:34.785Z,1667937694.785 [CBIT](INFO): Clearing failed state for component RudderServo 2022-11-08T20:01:34.785Z,1667937694.785 [RudderServo] No Fault, FailCount= 1 2022-11-08T20:01:34.856Z,1667937694.856 [WetLabsBB2FL](INFO): Powering down 2022-11-08T20:01:38.609Z,1667937698.609 [ThrusterHE](ERROR): Zero Speed Commanded. 2022-11-08T20:01:47.678Z,1667937707.678 [DAT](INFO): commRate: 800 2022-11-08T20:01:49.744Z,1667937709.744 [DAT](INFO): entering command mode 2022-11-08T20:01:49.945Z,1667937709.945 [DAT](INFO): setting verbose to 3 2022-11-08T20:01:50.198Z,1667937710.198 [DAT](INFO): set verbose to 3 2022-11-08T20:01:50.198Z,1667937710.198 [DAT](INFO): setting DatVerbose to 27440 2022-11-08T20:01:50.450Z,1667937710.450 [DAT](INFO): set DatVerbose to 27440 2022-11-08T20:01:50.450Z,1667937710.450 [DAT](INFO): setting transmit power to 8 2022-11-08T20:01:50.702Z,1667937710.702 [DAT](INFO): set transmit power to 8 2022-11-08T20:01:50.702Z,1667937710.702 [DAT](INFO): setting local address to 10 2022-11-08T20:01:50.954Z,1667937710.954 [DAT](INFO): set local address to 10 2022-11-08T20:01:50.955Z,1667937710.955 [DAT](INFO): Setting time to: 20:1:50 And date to:11/8/2022 2022-11-08T20:01:51.205Z,1667937711.205 [DAT](INFO): Local DAT time set to Tue Nov 8, 2022 20:01:50 2022-11-08T20:02:01.722Z,1667937721.722 [NAL9602](INFO): Powering up NAL9602 2022-11-08T20:02:12.651Z,1667937732.651 [NAL9602](INFO): NAL9602 initialized 2022-11-08T20:03:21.744Z,1667937801.744 [SBIT](IMPORTANT): Beginning Startup BIT 2022-11-08T20:03:21.765Z,1667937801.765 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-08T20:03:32.705Z,1667937812.705 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.013118 CHAN A1 (24V): 0.000504 CHAN A2 (12V): -0.004998 CHAN A3 (5V): 0.000573 CHAN B0 (3.3V): -0.001101 CHAN B1 (3.15aV): -0.001013 CHAN B2 (3.15bV): -0.001702 CHAN B3 (GND): -0.000435 OPEN: 0.004364 Full Scale: +/- 1 mA 2022-11-08T20:04:11.494Z,1667937851.494 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004555 2022-11-08T20:04:15.756Z,1667937855.756 [SBIT](IMPORTANT): SBIT PASSED 2022-11-08T20:04:15.756Z,1667937855.756 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2022-11-08T20:04:15.757Z,1667937855.757 [SBIT](IMPORTANT): BackseatComponent.needs24v=1 bool; 2022-11-08T20:04:15.757Z,1667937855.757 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none; 2022-11-08T20:04:15.757Z,1667937855.757 [SBIT](IMPORTANT): CBIT.gf24Offset=149 microampere; 2022-11-08T20:04:15.757Z,1667937855.757 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour; 2022-11-08T20:04:15.757Z,1667937855.757 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): Express none _.ayeris_disk_space; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 250.000000 count; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): Express none _.ayeris_particle_size; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=210.367112 cubic_centimeter; 2022-11-08T20:04:15.758Z,1667937855.758 [SBIT](IMPORTANT): VerticalControl.massDefault=22.333859 millimeter; 2022-11-08T20:04:16.162Z,1667937856.162 [MissionManager](IMPORTANT): Started mission Startup 2022-11-08T20:04:16.163Z,1667937856.163 [Startup] Running Loop=1 2022-11-08T20:04:16.163Z,1667937856.163 [Startup](DEBUG): Aggregate::initialize Startup 2022-11-08T20:04:16.163Z,1667937856.163 [Startup:A.GoToSurface] Running Loop=1 2022-11-08T20:04:16.163Z,1667937856.163 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:04:16.174Z,1667937856.174 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:04:16.174Z,1667937856.174 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:04:16.175Z,1667937856.175 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:04:16.175Z,1667937856.175 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:04:16.175Z,1667937856.175 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:04:16.177Z,1667937856.177 [Startup:StartupSatComms] Running Loop=1 2022-11-08T20:04:16.177Z,1667937856.177 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2022-11-08T20:04:16.182Z,1667937856.182 [Startup:StartupSatComms:A] Running Loop=1 2022-11-08T20:04:16.549Z,1667937856.549 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2022-11-08T20:04:32.297Z,1667937872.297 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2022-11-08T20:04:32.297Z,1667937872.297 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-08T20:04:32.298Z,1667937872.298 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2022-11-08T20:04:32.298Z,1667937872.298 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-08T20:04:32.308Z,1667937872.308 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-08T20:04:32.309Z,1667937872.309 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-08T20:04:32.718Z,1667937872.718 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-08T20:04:32.718Z,1667937872.718 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2022-11-08T20:04:32.719Z,1667937872.719 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-08T20:04:32.719Z,1667937872.719 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2022-11-08T20:04:33.121Z,1667937873.121 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T20:05:16.349Z,1667937916.349 [Startup:StartupSatComms:A](INFO): Timed out from 2022-11-08T20:04:16.2Z 2022-11-08T20:05:16.349Z,1667937916.349 [Startup:StartupSatComms:A] Stopped 2022-11-08T20:05:16.349Z,1667937916.349 [Startup:StartupSatComms:B] Running Loop=1 2022-11-08T20:05:16.824Z,1667937916.824 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-11-08T20:05:18.780Z,1667937918.780 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:05:18.781Z,1667937918.781 [DAT](INFO): setting remote address to 1 2022-11-08T20:05:19.035Z,1667937919.035 [DAT](INFO): set remote address to 1 2022-11-08T20:05:19.036Z,1667937919.036 [DAT](INFO): entering online mode 2022-11-08T20:05:19.288Z,1667937919.288 [DAT](INFO): commRate: 800 2022-11-08T20:05:19.288Z,1667937919.288 [DAT](INFO): online mode acknowledged 2022-11-08T20:05:19.288Z,1667937919.288 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:05:22.563Z,1667937922.563 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-08T20:05:23.253Z,1667937923.253 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221108T184519/Courier0022.lzma 2022-11-08T20:05:24.256Z,1667937924.256 [DataOverHttps](INFO): Moved sent file to Logs/20221108T184519/Courier0022.lzma.bak 2022-11-08T20:05:24.256Z,1667937924.256 [DataOverHttps](INFO): SBD MOMSN=17274617 2022-11-08T20:05:32.646Z,1667937932.646 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:05:33.534Z,1667937933.534 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:05:33.536Z,1667937933.536 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:05:36.811Z,1667937936.811 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-08T20:05:40.175Z,1667937940.175 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:40.175Z,1667937940.175 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:40.211Z,1667937940.211 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:05:40.213Z,1667937940.213 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:05:40.216Z,1667937940.216 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:05:40.219Z,1667937940.219 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:05:40.222Z,1667937940.222 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:05:40.227Z,1667937940.227 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:05:40.229Z,1667937940.229 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:40.241Z,1667937940.241 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20221108T200120/Courier0000.lzma 2022-11-08T20:05:41.243Z,1667937941.243 [DataOverHttps](INFO): Moved sent file to Logs/20221108T200120/Courier0000.lzma.bak 2022-11-08T20:05:41.244Z,1667937941.244 [DataOverHttps](INFO): SBD MOMSN=17274620 2022-11-08T20:05:45.812Z,1667937945.812 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:45.812Z,1667937945.812 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:05:45.830Z,1667937945.830 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:45.885Z,1667937945.885 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:05:45.895Z,1667937945.895 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:05:45.897Z,1667937945.897 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:05:45.911Z,1667937945.911 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:05:45.913Z,1667937945.913 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:05:45.934Z,1667937945.934 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:05:45.935Z,1667937945.935 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:49.940Z,1667937949.940 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:49.940Z,1667937949.940 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:05:49.942Z,1667937949.942 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:49.960Z,1667937949.960 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:05:49.991Z,1667937949.991 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:05:49.994Z,1667937949.994 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:05:49.995Z,1667937949.995 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:05:49.998Z,1667937949.998 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:05:50.002Z,1667937950.002 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:05:50.004Z,1667937950.004 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:05:53.950Z,1667937953.950 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:05:55.568Z,1667937955.568 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:05:55.574Z,1667937955.574 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:05:55.867Z,1667937955.867 [Startup:StartupSatComms:B] Stopped 2022-11-08T20:05:55.868Z,1667937955.868 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2022-11-08T20:05:55.868Z,1667937955.868 [Startup:StartupSatComms] Stopped 2022-11-08T20:05:55.868Z,1667937955.868 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2022-11-08T20:05:55.869Z,1667937955.869 [Startup](INFO): Completed Startup 2022-11-08T20:05:55.869Z,1667937955.869 [MissionManager](INFO): Startup is completed. 2022-11-08T20:05:55.869Z,1667937955.869 [MissionManager](INFO): Uninitializing Mission Startup 2022-11-08T20:05:55.869Z,1667937955.869 [Startup] Stopped 2022-11-08T20:05:55.869Z,1667937955.869 [Startup](DEBUG): Aggregate::uninitialize Startup 2022-11-08T20:05:55.869Z,1667937955.869 [Startup:A.GoToSurface] Stopped 2022-11-08T20:05:55.869Z,1667937955.869 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:05:56.263Z,1667937956.263 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:05:56.264Z,1667937956.264 [multiray_lab] Running Loop=1 2022-11-08T20:05:56.264Z,1667937956.264 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:05:57.515Z,1667937957.515 [multiray_lab](INFO): Timed out from 2022-11-08T20:05:56.3Z 2022-11-08T20:05:57.515Z,1667937957.515 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:05:57.515Z,1667937957.515 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:05:57.515Z,1667937957.515 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:05:57.516Z,1667937957.516 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:05:57.516Z,1667937957.516 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:05:57.516Z,1667937957.516 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:05:57.516Z,1667937957.516 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:05:57.516Z,1667937957.516 [multiray_lab] Stopped 2022-11-08T20:05:57.516Z,1667937957.516 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:05:57.951Z,1667937957.951 [MultiRay](INFO): White lights on 2022-11-08T20:05:58.014Z,1667937958.014 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:05:58.014Z,1667937958.014 [Default] Running Loop=1 2022-11-08T20:05:58.014Z,1667937958.014 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:05:58.015Z,1667937958.015 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:05:58.015Z,1667937958.015 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:05:58.015Z,1667937958.015 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:05:58.015Z,1667937958.015 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:05:58.016Z,1667937958.016 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:05:58.016Z,1667937958.016 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:05:58.016Z,1667937958.016 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:05:58.016Z,1667937958.016 [Default:A.Wait] Running Loop=1 2022-11-08T20:05:58.017Z,1667937958.017 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:05:58.847Z,1667937958.847 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-08T20:05:59.574Z,1667937959.574 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221108T184519/Express0023.lzma 2022-11-08T20:06:00.575Z,1667937960.575 [DataOverHttps](INFO): Moved sent file to Logs/20221108T184519/Express0023.lzma.bak 2022-11-08T20:06:00.576Z,1667937960.576 [DataOverHttps](INFO): SBD MOMSN=17274625 2022-11-08T20:06:11.219Z,1667937971.219 [Default:A.Wait](INFO): Done Waiting. 2022-11-08T20:06:11.220Z,1667937971.220 [Default:A.Wait] Stopped 2022-11-08T20:06:11.220Z,1667937971.220 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:06:11.620Z,1667937971.620 [Default:CheckIn] Running Loop=1 2022-11-08T20:06:11.620Z,1667937971.620 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-08T20:06:11.620Z,1667937971.620 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-08T20:06:12.033Z,1667937972.033 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-11-08T20:06:15.986Z,1667937975.986 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:06:16.238Z,1667937976.238 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:06:16.490Z,1667937976.490 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:06:22.204Z,1667937982.204 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:06:22.205Z,1667937982.205 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:06:22.223Z,1667937982.223 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:06:22.225Z,1667937982.225 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:06:22.252Z,1667937982.252 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:06:22.254Z,1667937982.254 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:06:22.256Z,1667937982.256 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:06:22.260Z,1667937982.260 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:06:22.262Z,1667937982.262 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T20:06:22.522Z,1667937982.522 [Default] Stopped 2022-11-08T20:06:22.522Z,1667937982.522 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:06:22.523Z,1667937982.523 [Default:B.GoToSurface] Stopped 2022-11-08T20:06:22.523Z,1667937982.523 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:06:22.523Z,1667937982.523 [Default:CheckIn] Stopped 2022-11-08T20:06:22.523Z,1667937982.523 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-08T20:06:22.523Z,1667937982.523 [Default:CheckIn:Read_GPS] Stopped 2022-11-08T20:06:22.523Z,1667937982.523 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:06:22.523Z,1667937982.523 [multiray_lab] Running Loop=1 2022-11-08T20:06:22.523Z,1667937982.523 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:06:23.731Z,1667937983.731 [multiray_lab](INFO): Timed out from 2022-11-08T20:06:22.5Z 2022-11-08T20:06:23.731Z,1667937983.731 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:06:23.731Z,1667937983.731 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:06:23.732Z,1667937983.732 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:06:23.732Z,1667937983.732 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:06:23.732Z,1667937983.732 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:06:23.732Z,1667937983.732 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:06:23.732Z,1667937983.732 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:06:23.733Z,1667937983.733 [multiray_lab] Stopped 2022-11-08T20:06:23.733Z,1667937983.733 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:06:24.281Z,1667937984.281 [MultiRay](INFO): White lights on 2022-11-08T20:06:24.314Z,1667937984.314 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:06:24.315Z,1667937984.315 [Default] Running Loop=1 2022-11-08T20:06:24.315Z,1667937984.315 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:06:24.316Z,1667937984.316 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:06:24.316Z,1667937984.316 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:06:24.318Z,1667937984.318 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:06:24.319Z,1667937984.319 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:06:24.319Z,1667937984.319 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:06:24.320Z,1667937984.320 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:06:24.320Z,1667937984.320 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:06:24.320Z,1667937984.320 [Default:A.Wait] Running Loop=1 2022-11-08T20:06:24.320Z,1667937984.320 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:06:26.574Z,1667937986.574 [DAT](FAULT): Buffer send receipt timeout failure. 2022-11-08T20:06:26.574Z,1667937986.574 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:06:26.826Z,1667937986.826 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:06:27.078Z,1667937987.078 [DAT](INFO): entering online mode 2022-11-08T20:06:27.330Z,1667937987.330 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:27.582Z,1667937987.582 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:27.834Z,1667937987.834 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:28.086Z,1667937988.086 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:28.338Z,1667937988.338 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:28.590Z,1667937988.590 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:28.842Z,1667937988.842 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:29.036Z,1667937989.036 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:29.036Z,1667937989.036 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:29.079Z,1667937989.079 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:06:29.082Z,1667937989.082 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:06:29.084Z,1667937989.084 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:06:29.087Z,1667937989.087 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:06:29.090Z,1667937989.090 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:06:29.094Z,1667937989.094 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:29.096Z,1667937989.096 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:06:29.100Z,1667937989.100 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:29.346Z,1667937989.346 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:29.401Z,1667937989.401 [Default] Stopped 2022-11-08T20:06:29.402Z,1667937989.402 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:06:29.402Z,1667937989.402 [Default:A.Wait] Stopped 2022-11-08T20:06:29.402Z,1667937989.402 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:06:29.402Z,1667937989.402 [Default:B.GoToSurface] Stopped 2022-11-08T20:06:29.402Z,1667937989.402 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:06:29.402Z,1667937989.402 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:06:29.402Z,1667937989.402 [multiray_lab] Running Loop=1 2022-11-08T20:06:29.403Z,1667937989.403 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:06:29.598Z,1667937989.598 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:29.850Z,1667937989.850 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:30.102Z,1667937990.102 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:30.354Z,1667937990.354 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:30.606Z,1667937990.606 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:30.620Z,1667937990.620 [multiray_lab](INFO): Timed out from 2022-11-08T20:06:29.4Z 2022-11-08T20:06:30.620Z,1667937990.620 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:06:30.620Z,1667937990.620 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:06:30.620Z,1667937990.620 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:06:30.621Z,1667937990.621 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:06:30.621Z,1667937990.621 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:06:30.621Z,1667937990.621 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:06:30.621Z,1667937990.621 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:06:30.621Z,1667937990.621 [multiray_lab] Stopped 2022-11-08T20:06:30.621Z,1667937990.621 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:06:30.858Z,1667937990.858 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:31.113Z,1667937991.113 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:31.143Z,1667937991.143 [MultiRay](INFO): Red lights on 2022-11-08T20:06:31.192Z,1667937991.192 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:06:31.192Z,1667937991.192 [Default] Running Loop=1 2022-11-08T20:06:31.192Z,1667937991.192 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:06:31.192Z,1667937991.192 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:06:31.192Z,1667937991.192 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:06:31.193Z,1667937991.193 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:06:31.193Z,1667937991.193 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:06:31.193Z,1667937991.193 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:06:31.194Z,1667937991.194 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:06:31.194Z,1667937991.194 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:06:31.195Z,1667937991.195 [Default:A.Wait] Running Loop=1 2022-11-08T20:06:31.195Z,1667937991.195 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:06:31.362Z,1667937991.362 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:31.614Z,1667937991.614 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:31.866Z,1667937991.866 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:32.119Z,1667937992.119 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:32.370Z,1667937992.370 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:32.622Z,1667937992.622 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:32.874Z,1667937992.874 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:33.126Z,1667937993.126 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:33.378Z,1667937993.378 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:33.630Z,1667937993.630 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:33.884Z,1667937993.884 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:34.134Z,1667937994.134 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:34.386Z,1667937994.386 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:34.638Z,1667937994.638 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:34.890Z,1667937994.890 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:35.088Z,1667937995.088 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T20:06:35.089Z,1667937995.089 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T20:06:35.142Z,1667937995.142 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:35.143Z,1667937995.143 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:06:35.145Z,1667937995.145 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:06:35.147Z,1667937995.147 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:06:35.149Z,1667937995.149 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:06:35.151Z,1667937995.151 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:06:35.156Z,1667937995.156 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:06:35.157Z,1667937995.157 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T20:06:35.394Z,1667937995.394 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:35.472Z,1667937995.472 [Default] Stopped 2022-11-08T20:06:35.472Z,1667937995.472 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:06:35.472Z,1667937995.472 [Default:A.Wait] Stopped 2022-11-08T20:06:35.472Z,1667937995.472 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:06:35.472Z,1667937995.472 [Default:B.GoToSurface] Stopped 2022-11-08T20:06:35.472Z,1667937995.472 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:06:35.473Z,1667937995.473 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:06:35.473Z,1667937995.473 [multiray_lab] Running Loop=1 2022-11-08T20:06:35.473Z,1667937995.473 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:06:35.646Z,1667937995.646 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:35.906Z,1667937995.906 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:36.158Z,1667937996.158 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:36.410Z,1667937996.410 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:36.656Z,1667937996.656 [multiray_lab](INFO): Timed out from 2022-11-08T20:06:35.5Z 2022-11-08T20:06:36.656Z,1667937996.656 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:06:36.656Z,1667937996.656 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:06:36.656Z,1667937996.656 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:06:36.657Z,1667937996.657 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:06:36.657Z,1667937996.657 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:06:36.657Z,1667937996.657 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:06:36.657Z,1667937996.657 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:06:36.658Z,1667937996.658 [multiray_lab] Stopped 2022-11-08T20:06:36.658Z,1667937996.658 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:06:36.662Z,1667937996.662 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:36.914Z,1667937996.914 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:37.134Z,1667937997.134 [MultiRay](IMPORTANT): All lights off 2022-11-08T20:06:37.165Z,1667937997.165 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:06:37.165Z,1667937997.165 [Default] Running Loop=1 2022-11-08T20:06:37.165Z,1667937997.165 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:06:37.166Z,1667937997.166 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:37.165Z,1667937997.165 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:06:37.167Z,1667937997.167 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:06:37.167Z,1667937997.167 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:06:37.167Z,1667937997.167 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:06:37.168Z,1667937997.168 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:06:37.168Z,1667937997.168 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:06:37.168Z,1667937997.168 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:06:37.168Z,1667937997.168 [Default:A.Wait] Running Loop=1 2022-11-08T20:06:37.169Z,1667937997.169 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:06:37.418Z,1667937997.418 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:37.670Z,1667937997.670 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:37.922Z,1667937997.922 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:38.174Z,1667937998.174 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:38.426Z,1667937998.426 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:38.678Z,1667937998.678 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:38.930Z,1667937998.930 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:39.182Z,1667937999.182 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:39.434Z,1667937999.434 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:39.686Z,1667937999.686 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:39.938Z,1667937999.938 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:40.190Z,1667938000.190 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:40.442Z,1667938000.442 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:40.694Z,1667938000.694 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:40.912Z,1667938000.912 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:40.912Z,1667938000.912 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:40.946Z,1667938000.946 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:40.965Z,1667938000.965 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:06:40.967Z,1667938000.967 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:06:40.969Z,1667938000.969 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:06:40.999Z,1667938000.999 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:06:41.001Z,1667938001.001 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:06:41.005Z,1667938001.005 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:06:41.019Z,1667938001.019 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:41.145Z,1667938001.145 [Default] Stopped 2022-11-08T20:06:41.145Z,1667938001.145 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:06:41.145Z,1667938001.145 [Default:A.Wait] Stopped 2022-11-08T20:06:41.145Z,1667938001.145 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:06:41.150Z,1667938001.150 [Default:B.GoToSurface] Stopped 2022-11-08T20:06:41.150Z,1667938001.150 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:06:41.150Z,1667938001.150 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:06:41.150Z,1667938001.150 [multiray_lab] Running Loop=1 2022-11-08T20:06:41.150Z,1667938001.150 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:06:41.198Z,1667938001.198 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:41.450Z,1667938001.450 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:41.702Z,1667938001.702 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:41.954Z,1667938001.954 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:42.206Z,1667938002.206 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:06:42.206Z,1667938002.206 [DAT](FAULT): failed to enter online mode 2022-11-08T20:06:42.206Z,1667938002.206 [DAT](FAULT): Failure returning to online mode 2022-11-08T20:06:42.206Z,1667938002.206 [DAT] Communications Fault, FailCount= 1 2022-11-08T20:06:42.207Z,1667938002.207 [DAT](ERROR): Communications Fault 2022-11-08T20:06:42.315Z,1667938002.315 [multiray_lab](INFO): Timed out from 2022-11-08T20:06:41.2Z 2022-11-08T20:06:42.315Z,1667938002.315 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:06:42.315Z,1667938002.315 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:06:42.316Z,1667938002.316 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:06:42.316Z,1667938002.316 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:06:42.316Z,1667938002.316 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:06:42.316Z,1667938002.316 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:06:42.316Z,1667938002.316 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:06:42.316Z,1667938002.316 [multiray_lab] Stopped 2022-11-08T20:06:42.317Z,1667938002.317 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:06:42.426Z,1667938002.426 [CBIT](ERROR): Communications Fault in component: DAT 2022-11-08T20:06:42.610Z,1667938002.610 [DAT](INFO): Powering down 2022-11-08T20:06:42.763Z,1667938002.763 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:06:42.764Z,1667938002.764 [Default] Running Loop=1 2022-11-08T20:06:42.764Z,1667938002.764 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:06:42.764Z,1667938002.764 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:06:42.764Z,1667938002.764 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:06:42.764Z,1667938002.764 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:06:42.764Z,1667938002.764 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:06:42.765Z,1667938002.765 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:06:42.765Z,1667938002.765 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:06:42.770Z,1667938002.770 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:06:42.770Z,1667938002.770 [Default:A.Wait] Running Loop=1 2022-11-08T20:06:42.770Z,1667938002.770 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:06:43.544Z,1667938003.544 [CBIT](INFO): Clearing failed state for component DAT 2022-11-08T20:06:43.544Z,1667938003.544 [DAT] No Fault, FailCount= 1 2022-11-08T20:06:45.654Z,1667938005.654 [DAT](INFO): Powering up 2022-11-08T20:06:45.654Z,1667938005.654 [DAT](DEBUG): Initializing DAT. 2022-11-08T20:06:47.820Z,1667938007.820 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:47.820Z,1667938007.820 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:47.844Z,1667938007.844 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:06:47.862Z,1667938007.862 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:06:47.864Z,1667938007.864 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:06:47.875Z,1667938007.875 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:06:47.877Z,1667938007.877 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:06:47.885Z,1667938007.885 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:06:47.891Z,1667938007.891 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:47.972Z,1667938007.972 [Default] Stopped 2022-11-08T20:06:47.972Z,1667938007.972 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:06:47.972Z,1667938007.972 [Default:A.Wait] Stopped 2022-11-08T20:06:47.972Z,1667938007.972 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:06:47.972Z,1667938007.972 [Default:B.GoToSurface] Stopped 2022-11-08T20:06:47.972Z,1667938007.972 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:06:47.972Z,1667938007.972 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:06:47.973Z,1667938007.973 [multiray_lab] Running Loop=1 2022-11-08T20:06:47.973Z,1667938007.973 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:06:49.180Z,1667938009.180 [multiray_lab](INFO): Timed out from 2022-11-08T20:06:47.0Z 2022-11-08T20:06:49.180Z,1667938009.180 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:06:49.180Z,1667938009.180 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:06:49.180Z,1667938009.180 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:06:49.181Z,1667938009.181 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:06:49.181Z,1667938009.181 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:06:49.181Z,1667938009.181 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:06:49.181Z,1667938009.181 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:06:49.181Z,1667938009.181 [multiray_lab] Stopped 2022-11-08T20:06:49.181Z,1667938009.181 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:06:49.587Z,1667938009.587 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:06:49.587Z,1667938009.587 [Default] Running Loop=1 2022-11-08T20:06:49.587Z,1667938009.587 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:06:49.587Z,1667938009.587 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:06:49.587Z,1667938009.587 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:06:49.587Z,1667938009.587 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:06:49.588Z,1667938009.588 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:06:49.588Z,1667938009.588 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:06:49.588Z,1667938009.588 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:06:49.589Z,1667938009.589 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:06:49.589Z,1667938009.589 [Default:A.Wait] Running Loop=1 2022-11-08T20:06:49.589Z,1667938009.589 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:06:53.559Z,1667938013.559 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:53.560Z,1667938013.560 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:53.660Z,1667938013.660 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:06:53.662Z,1667938013.662 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:06:53.664Z,1667938013.664 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:06:53.666Z,1667938013.666 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:06:53.668Z,1667938013.668 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:06:53.672Z,1667938013.672 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:06:53.674Z,1667938013.674 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:54.031Z,1667938014.031 [Default] Stopped 2022-11-08T20:06:54.031Z,1667938014.031 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:06:54.031Z,1667938014.031 [Default:A.Wait] Stopped 2022-11-08T20:06:54.032Z,1667938014.032 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:06:54.032Z,1667938014.032 [Default:B.GoToSurface] Stopped 2022-11-08T20:06:54.032Z,1667938014.032 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:06:54.032Z,1667938014.032 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:06:54.032Z,1667938014.032 [multiray_lab] Running Loop=1 2022-11-08T20:06:54.032Z,1667938014.032 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:06:55.242Z,1667938015.242 [multiray_lab](INFO): Timed out from 2022-11-08T20:06:54.0Z 2022-11-08T20:06:55.242Z,1667938015.242 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:06:55.242Z,1667938015.242 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:06:55.242Z,1667938015.242 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:06:55.243Z,1667938015.243 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:06:55.243Z,1667938015.243 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:06:55.243Z,1667938015.243 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:06:55.243Z,1667938015.243 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:06:55.243Z,1667938015.243 [multiray_lab] Stopped 2022-11-08T20:06:55.243Z,1667938015.243 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:06:55.647Z,1667938015.647 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:06:55.647Z,1667938015.647 [Default] Running Loop=1 2022-11-08T20:06:55.647Z,1667938015.647 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:06:55.647Z,1667938015.647 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:06:55.647Z,1667938015.647 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:06:55.647Z,1667938015.647 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:06:55.648Z,1667938015.648 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:06:55.648Z,1667938015.648 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:06:55.648Z,1667938015.648 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:06:55.649Z,1667938015.649 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:06:55.649Z,1667938015.649 [Default:A.Wait] Running Loop=1 2022-11-08T20:06:55.649Z,1667938015.649 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:06:58.801Z,1667938018.801 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:58.801Z,1667938018.801 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:58.819Z,1667938018.819 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:06:58.821Z,1667938018.821 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:06:58.823Z,1667938018.823 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:06:58.825Z,1667938018.825 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:06:58.827Z,1667938018.827 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:06:58.831Z,1667938018.831 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:06:58.833Z,1667938018.833 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:06:58.901Z,1667938018.901 [Default] Stopped 2022-11-08T20:06:58.901Z,1667938018.901 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:06:58.902Z,1667938018.902 [Default:A.Wait] Stopped 2022-11-08T20:06:58.902Z,1667938018.902 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:06:58.902Z,1667938018.902 [Default:B.GoToSurface] Stopped 2022-11-08T20:06:58.902Z,1667938018.902 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:06:58.902Z,1667938018.902 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:06:58.902Z,1667938018.902 [multiray_lab] Running Loop=1 2022-11-08T20:06:58.902Z,1667938018.902 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:07:00.088Z,1667938020.088 [multiray_lab](INFO): Timed out from 2022-11-08T20:06:58.9Z 2022-11-08T20:07:00.088Z,1667938020.088 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:07:00.088Z,1667938020.088 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:07:00.088Z,1667938020.088 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:07:00.089Z,1667938020.089 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:07:00.089Z,1667938020.089 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:07:00.089Z,1667938020.089 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:07:00.089Z,1667938020.089 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:07:00.089Z,1667938020.089 [multiray_lab] Stopped 2022-11-08T20:07:00.089Z,1667938020.089 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:07:00.494Z,1667938020.494 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:07:00.495Z,1667938020.495 [Default] Running Loop=1 2022-11-08T20:07:00.495Z,1667938020.495 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:07:00.495Z,1667938020.495 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:07:00.495Z,1667938020.495 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:07:00.495Z,1667938020.495 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:07:00.496Z,1667938020.496 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:07:00.496Z,1667938020.496 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:07:00.496Z,1667938020.496 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:07:00.496Z,1667938020.496 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:07:00.497Z,1667938020.497 [Default:A.Wait] Running Loop=1 2022-11-08T20:07:00.497Z,1667938020.497 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:07:00.532Z,1667938020.532 [DAT](INFO): commRate: 800 2022-11-08T20:07:02.598Z,1667938022.598 [DAT](INFO): entering command mode 2022-11-08T20:07:02.799Z,1667938022.799 [DAT](INFO): setting verbose to 3 2022-11-08T20:07:03.051Z,1667938023.051 [DAT](INFO): set verbose to 3 2022-11-08T20:07:03.052Z,1667938023.052 [DAT](INFO): setting DatVerbose to 27440 2022-11-08T20:07:03.307Z,1667938023.307 [DAT](INFO): set DatVerbose to 27440 2022-11-08T20:07:03.307Z,1667938023.307 [DAT](INFO): setting transmit power to 8 2022-11-08T20:07:03.559Z,1667938023.559 [DAT](INFO): set transmit power to 8 2022-11-08T20:07:03.560Z,1667938023.560 [DAT](INFO): setting local address to 10 2022-11-08T20:07:03.811Z,1667938023.811 [DAT](INFO): set local address to 10 2022-11-08T20:07:03.812Z,1667938023.812 [DAT](INFO): Setting time to: 20:7:3 And date to:11/8/2022 2022-11-08T20:07:04.063Z,1667938024.063 [DAT](INFO): Local DAT time set to Tue Nov 8, 2022 20:07:03 2022-11-08T20:07:04.064Z,1667938024.064 [DAT](INFO): setting remote address to 1 2022-11-08T20:07:04.316Z,1667938024.316 [DAT](INFO): set remote address to 1 2022-11-08T20:07:04.316Z,1667938024.316 [DAT](INFO): entering online mode 2022-11-08T20:07:04.568Z,1667938024.568 [DAT](INFO): commRate: 800 2022-11-08T20:07:04.568Z,1667938024.568 [DAT](INFO): online mode acknowledged 2022-11-08T20:07:04.568Z,1667938024.568 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:07:06.631Z,1667938026.631 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:06.631Z,1667938026.631 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:06.651Z,1667938026.651 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:07:06.653Z,1667938026.653 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:07:06.655Z,1667938026.655 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:07:06.657Z,1667938026.657 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:07:06.659Z,1667938026.659 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:07:06.663Z,1667938026.663 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:07:06.665Z,1667938026.665 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:06.972Z,1667938026.972 [Default] Stopped 2022-11-08T20:07:06.972Z,1667938026.972 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:07:06.972Z,1667938026.972 [Default:A.Wait] Stopped 2022-11-08T20:07:06.972Z,1667938026.972 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:07:06.972Z,1667938026.972 [Default:B.GoToSurface] Stopped 2022-11-08T20:07:06.972Z,1667938026.972 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:07:06.972Z,1667938026.972 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:07:06.973Z,1667938026.973 [multiray_lab] Running Loop=1 2022-11-08T20:07:06.973Z,1667938026.973 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:07:08.168Z,1667938028.168 [multiray_lab](INFO): Timed out from 2022-11-08T20:07:06.0Z 2022-11-08T20:07:08.168Z,1667938028.168 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:07:08.168Z,1667938028.168 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:07:08.169Z,1667938028.169 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:07:08.169Z,1667938028.169 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:07:08.169Z,1667938028.169 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:07:08.169Z,1667938028.169 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:07:08.170Z,1667938028.170 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:07:08.170Z,1667938028.170 [multiray_lab] Stopped 2022-11-08T20:07:08.170Z,1667938028.170 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:07:08.577Z,1667938028.577 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:07:08.578Z,1667938028.578 [Default] Running Loop=1 2022-11-08T20:07:08.578Z,1667938028.578 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:07:08.578Z,1667938028.578 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:07:08.578Z,1667938028.578 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:07:08.578Z,1667938028.578 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:07:08.579Z,1667938028.579 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:07:08.579Z,1667938028.579 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:07:08.579Z,1667938028.579 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:07:08.579Z,1667938028.579 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:07:08.580Z,1667938028.580 [Default:A.Wait] Running Loop=1 2022-11-08T20:07:08.580Z,1667938028.580 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:07:11.847Z,1667938031.847 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:11.848Z,1667938031.848 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:11.905Z,1667938031.905 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:07:11.907Z,1667938031.907 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:07:11.909Z,1667938031.909 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:07:11.911Z,1667938031.911 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:07:11.914Z,1667938031.914 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:07:11.918Z,1667938031.918 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:07:11.920Z,1667938031.920 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:12.243Z,1667938032.243 [Default] Stopped 2022-11-08T20:07:12.243Z,1667938032.243 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:07:12.243Z,1667938032.243 [Default:A.Wait] Stopped 2022-11-08T20:07:12.243Z,1667938032.243 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:07:12.243Z,1667938032.243 [Default:B.GoToSurface] Stopped 2022-11-08T20:07:12.244Z,1667938032.244 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:07:12.244Z,1667938032.244 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:07:12.244Z,1667938032.244 [multiray_lab] Running Loop=1 2022-11-08T20:07:12.244Z,1667938032.244 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:07:13.421Z,1667938033.421 [multiray_lab](INFO): Timed out from 2022-11-08T20:07:12.2Z 2022-11-08T20:07:13.421Z,1667938033.421 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:07:13.421Z,1667938033.421 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:07:13.421Z,1667938033.421 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:07:13.422Z,1667938033.422 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:07:13.422Z,1667938033.422 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:07:13.422Z,1667938033.422 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:07:13.422Z,1667938033.422 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:07:13.422Z,1667938033.422 [multiray_lab] Stopped 2022-11-08T20:07:13.422Z,1667938033.422 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:07:13.831Z,1667938033.831 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:07:13.831Z,1667938033.831 [Default] Running Loop=1 2022-11-08T20:07:13.831Z,1667938033.831 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:07:13.831Z,1667938033.831 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:07:13.831Z,1667938033.831 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:07:13.831Z,1667938033.831 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:07:13.832Z,1667938033.832 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:07:13.832Z,1667938033.832 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:07:13.832Z,1667938033.832 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:07:13.833Z,1667938033.833 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:07:13.833Z,1667938033.833 [Default:A.Wait] Running Loop=1 2022-11-08T20:07:13.833Z,1667938033.833 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:07:14.654Z,1667938034.654 [DAT](FAULT): Buffer send receipt timeout failure. 2022-11-08T20:07:14.654Z,1667938034.654 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:07:14.906Z,1667938034.906 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:07:15.158Z,1667938035.158 [DAT](INFO): entering online mode 2022-11-08T20:07:15.410Z,1667938035.410 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:15.662Z,1667938035.662 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:15.914Z,1667938035.914 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:16.166Z,1667938036.166 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:16.244Z,1667938036.244 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-08T20:07:16.418Z,1667938036.418 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:16.670Z,1667938036.670 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:16.922Z,1667938036.922 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:17.174Z,1667938037.174 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:17.426Z,1667938037.426 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:17.678Z,1667938037.678 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:17.931Z,1667938037.931 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:18.182Z,1667938038.182 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:18.200Z,1667938038.200 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:18.200Z,1667938038.200 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:18.240Z,1667938038.240 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:07:18.314Z,1667938038.314 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:07:18.327Z,1667938038.327 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:07:18.329Z,1667938038.329 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:07:18.336Z,1667938038.336 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:07:18.352Z,1667938038.352 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:07:18.366Z,1667938038.366 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:18.434Z,1667938038.434 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:18.686Z,1667938038.686 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:18.703Z,1667938038.703 [Default] Stopped 2022-11-08T20:07:18.703Z,1667938038.703 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:07:18.703Z,1667938038.703 [Default:A.Wait] Stopped 2022-11-08T20:07:18.703Z,1667938038.703 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:07:18.703Z,1667938038.703 [Default:B.GoToSurface] Stopped 2022-11-08T20:07:18.703Z,1667938038.703 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:07:18.703Z,1667938038.703 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:07:18.704Z,1667938038.704 [multiray_lab] Running Loop=1 2022-11-08T20:07:18.704Z,1667938038.704 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:07:18.941Z,1667938038.941 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:19.190Z,1667938039.190 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:19.442Z,1667938039.442 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:19.694Z,1667938039.694 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:19.920Z,1667938039.920 [multiray_lab](INFO): Timed out from 2022-11-08T20:07:18.7Z 2022-11-08T20:07:19.920Z,1667938039.920 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:07:19.920Z,1667938039.920 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:07:19.921Z,1667938039.921 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:07:19.921Z,1667938039.921 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:07:19.921Z,1667938039.921 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:07:19.922Z,1667938039.922 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:07:19.922Z,1667938039.922 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:07:19.922Z,1667938039.922 [multiray_lab] Stopped 2022-11-08T20:07:19.922Z,1667938039.922 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:07:19.948Z,1667938039.948 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:20.198Z,1667938040.198 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:20.332Z,1667938040.332 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:07:20.332Z,1667938040.332 [Default] Running Loop=1 2022-11-08T20:07:20.332Z,1667938040.332 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:07:20.332Z,1667938040.332 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:07:20.332Z,1667938040.332 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:07:20.333Z,1667938040.333 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:07:20.333Z,1667938040.333 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:07:20.333Z,1667938040.333 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:07:20.334Z,1667938040.334 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:07:20.334Z,1667938040.334 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:07:20.334Z,1667938040.334 [Default:A.Wait] Running Loop=1 2022-11-08T20:07:20.334Z,1667938040.334 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:07:20.451Z,1667938040.451 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:20.702Z,1667938040.702 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:20.954Z,1667938040.954 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:21.206Z,1667938041.206 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:21.458Z,1667938041.458 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:21.710Z,1667938041.710 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:21.962Z,1667938041.962 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:22.214Z,1667938042.214 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:22.466Z,1667938042.466 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:22.718Z,1667938042.718 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:22.883Z,1667938042.883 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:22.884Z,1667938042.884 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:22.915Z,1667938042.915 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:07:22.917Z,1667938042.917 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:07:22.919Z,1667938042.919 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:07:22.921Z,1667938042.921 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:07:22.929Z,1667938042.929 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:07:22.934Z,1667938042.934 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:07:22.936Z,1667938042.936 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:07:22.970Z,1667938042.970 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:23.168Z,1667938043.168 [Default] Stopped 2022-11-08T20:07:23.168Z,1667938043.168 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:07:23.168Z,1667938043.168 [Default:A.Wait] Stopped 2022-11-08T20:07:23.168Z,1667938043.168 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:07:23.169Z,1667938043.169 [Default:B.GoToSurface] Stopped 2022-11-08T20:07:23.169Z,1667938043.169 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:07:23.169Z,1667938043.169 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:07:23.169Z,1667938043.169 [multiray_lab] Running Loop=1 2022-11-08T20:07:23.169Z,1667938043.169 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:07:23.222Z,1667938043.222 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:23.474Z,1667938043.474 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:23.726Z,1667938043.726 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:23.978Z,1667938043.978 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:24.230Z,1667938044.230 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:24.409Z,1667938044.409 [multiray_lab](INFO): Timed out from 2022-11-08T20:07:23.2Z 2022-11-08T20:07:24.409Z,1667938044.409 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:07:24.409Z,1667938044.409 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:07:24.427Z,1667938044.427 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:07:24.427Z,1667938044.427 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:07:24.427Z,1667938044.427 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:07:24.428Z,1667938044.428 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:07:24.428Z,1667938044.428 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:07:24.428Z,1667938044.428 [multiray_lab] Stopped 2022-11-08T20:07:24.428Z,1667938044.428 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:07:24.482Z,1667938044.482 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:24.734Z,1667938044.734 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:24.744Z,1667938044.744 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-11-08T20:07:24.748Z,1667938044.748 [BPC1](INFO): Received data from all battery sticks. 2022-11-08T20:07:24.758Z,1667938044.758 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:07:24.758Z,1667938044.758 [Default] Running Loop=1 2022-11-08T20:07:24.758Z,1667938044.758 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:07:24.758Z,1667938044.758 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:07:24.758Z,1667938044.758 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:07:24.759Z,1667938044.759 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:07:24.759Z,1667938044.759 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:07:24.759Z,1667938044.759 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:07:24.760Z,1667938044.760 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:07:24.760Z,1667938044.760 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:07:24.760Z,1667938044.760 [Default:A.Wait] Running Loop=1 2022-11-08T20:07:24.760Z,1667938044.760 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:07:24.986Z,1667938044.986 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:25.238Z,1667938045.238 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:25.490Z,1667938045.490 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:25.742Z,1667938045.742 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:25.994Z,1667938045.994 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:26.246Z,1667938046.246 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:26.498Z,1667938046.498 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:26.756Z,1667938046.756 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:27.006Z,1667938047.006 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:27.258Z,1667938047.258 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:27.510Z,1667938047.510 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:27.762Z,1667938047.762 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:28.014Z,1667938048.014 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:28.266Z,1667938048.266 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:28.518Z,1667938048.518 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:28.774Z,1667938048.774 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:29.026Z,1667938049.026 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:29.278Z,1667938049.278 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:29.530Z,1667938049.530 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:29.782Z,1667938049.782 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:30.034Z,1667938050.034 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:30.286Z,1667938050.286 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:07:30.286Z,1667938050.286 [DAT](FAULT): failed to enter online mode 2022-11-08T20:07:30.286Z,1667938050.286 [DAT](FAULT): Failure returning to online mode 2022-11-08T20:07:30.287Z,1667938050.287 [DAT] Communications Fault, FailCount= 2 2022-11-08T20:07:30.287Z,1667938050.287 [DAT](ERROR): Communications Fault 2022-11-08T20:07:30.424Z,1667938050.424 [CBIT](ERROR): Communications Fault in component: DAT 2022-11-08T20:07:30.690Z,1667938050.690 [DAT](INFO): Powering down 2022-11-08T20:07:31.624Z,1667938051.624 [CBIT](INFO): Clearing failed state for component DAT 2022-11-08T20:07:31.624Z,1667938051.624 [DAT] No Fault, FailCount= 2 2022-11-08T20:07:33.230Z,1667938053.230 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2022-11-08T20:07:33.230Z,1667938053.230 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-08T20:07:33.231Z,1667938053.231 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2022-11-08T20:07:33.231Z,1667938053.231 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-08T20:07:33.241Z,1667938053.241 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-08T20:07:33.242Z,1667938053.242 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-08T20:07:33.650Z,1667938053.650 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-08T20:07:33.650Z,1667938053.650 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2022-11-08T20:07:33.651Z,1667938053.651 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-08T20:07:33.651Z,1667938053.651 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2022-11-08T20:07:33.746Z,1667938053.746 [DAT](INFO): Powering up 2022-11-08T20:07:33.746Z,1667938053.746 [DAT](DEBUG): Initializing DAT. 2022-11-08T20:07:34.050Z,1667938054.050 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T20:07:38.108Z,1667938058.108 [Default:A.Wait](INFO): Done Waiting. 2022-11-08T20:07:38.108Z,1667938058.108 [Default:A.Wait] Stopped 2022-11-08T20:07:38.108Z,1667938058.108 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:07:38.513Z,1667938058.513 [Default:CheckIn] Running Loop=1 2022-11-08T20:07:38.513Z,1667938058.513 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-08T20:07:38.513Z,1667938058.513 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-08T20:07:48.630Z,1667938068.630 [DAT](INFO): commRate: 800 2022-11-08T20:07:50.694Z,1667938070.694 [DAT](INFO): entering command mode 2022-11-08T20:07:50.895Z,1667938070.895 [DAT](INFO): setting verbose to 3 2022-11-08T20:07:51.147Z,1667938071.147 [DAT](INFO): set verbose to 3 2022-11-08T20:07:51.148Z,1667938071.148 [DAT](INFO): setting DatVerbose to 27440 2022-11-08T20:07:51.399Z,1667938071.399 [DAT](INFO): set DatVerbose to 27440 2022-11-08T20:07:51.399Z,1667938071.399 [DAT](INFO): setting transmit power to 8 2022-11-08T20:07:51.651Z,1667938071.651 [DAT](INFO): set transmit power to 8 2022-11-08T20:07:51.651Z,1667938071.651 [DAT](INFO): setting local address to 10 2022-11-08T20:07:51.903Z,1667938071.903 [DAT](INFO): set local address to 10 2022-11-08T20:07:51.904Z,1667938071.904 [DAT](INFO): Setting time to: 20:7:51 And date to:11/8/2022 2022-11-08T20:07:52.155Z,1667938072.155 [DAT](INFO): Local DAT time set to Tue Nov 8, 2022 20:07:51 2022-11-08T20:07:52.156Z,1667938072.156 [DAT](INFO): setting remote address to 1 2022-11-08T20:07:52.407Z,1667938072.407 [DAT](INFO): set remote address to 1 2022-11-08T20:07:52.408Z,1667938072.408 [DAT](INFO): entering online mode 2022-11-08T20:07:52.660Z,1667938072.660 [DAT](INFO): commRate: 800 2022-11-08T20:07:52.660Z,1667938072.660 [DAT](INFO): online mode acknowledged 2022-11-08T20:07:52.660Z,1667938072.660 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:07:55.935Z,1667938075.935 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-08T20:08:01.129Z,1667938081.129 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:08:01.129Z,1667938081.129 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:08:01.186Z,1667938081.186 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T20:08:01.188Z,1667938081.188 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T20:08:01.204Z,1667938081.204 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T20:08:01.222Z,1667938081.222 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T20:08:01.224Z,1667938081.224 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T20:08:01.233Z,1667938081.233 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T20:08:01.239Z,1667938081.239 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T20:08:01.546Z,1667938081.546 [Default] Stopped 2022-11-08T20:08:01.546Z,1667938081.546 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:08:01.546Z,1667938081.546 [Default:B.GoToSurface] Stopped 2022-11-08T20:08:01.546Z,1667938081.546 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:08:01.546Z,1667938081.546 [Default:CheckIn] Stopped 2022-11-08T20:08:01.547Z,1667938081.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-08T20:08:01.547Z,1667938081.547 [Default:CheckIn:Read_GPS] Stopped 2022-11-08T20:08:01.547Z,1667938081.547 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T20:08:01.547Z,1667938081.547 [multiray_lab] Running Loop=1 2022-11-08T20:08:01.547Z,1667938081.547 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T20:08:02.727Z,1667938082.727 [multiray_lab](INFO): Timed out from 2022-11-08T20:08:01.5Z 2022-11-08T20:08:02.727Z,1667938082.727 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T20:08:02.727Z,1667938082.727 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T20:08:02.727Z,1667938082.727 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T20:08:02.728Z,1667938082.728 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T20:08:02.728Z,1667938082.728 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T20:08:02.728Z,1667938082.728 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T20:08:02.728Z,1667938082.728 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T20:08:02.728Z,1667938082.728 [multiray_lab] Stopped 2022-11-08T20:08:02.728Z,1667938082.728 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T20:08:03.138Z,1667938083.138 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T20:08:03.138Z,1667938083.138 [Default] Running Loop=1 2022-11-08T20:08:03.139Z,1667938083.139 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T20:08:03.139Z,1667938083.139 [Default:B.GoToSurface] Running Loop=1 2022-11-08T20:08:03.139Z,1667938083.139 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T20:08:03.139Z,1667938083.139 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T20:08:03.139Z,1667938083.139 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T20:08:03.140Z,1667938083.140 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T20:08:03.140Z,1667938083.140 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T20:08:03.140Z,1667938083.140 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T20:08:03.141Z,1667938083.141 [Default:A.Wait] Running Loop=1 2022-11-08T20:08:03.141Z,1667938083.141 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T20:08:13.074Z,1667938093.074 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:08:13.326Z,1667938093.326 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:08:13.578Z,1667938093.578 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:08:16.477Z,1667938096.477 [Default:A.Wait](INFO): Done Waiting. 2022-11-08T20:08:16.477Z,1667938096.477 [Default:A.Wait] Stopped 2022-11-08T20:08:16.477Z,1667938096.477 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T20:08:16.855Z,1667938096.855 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-08T20:08:16.866Z,1667938096.866 [Default:CheckIn] Running Loop=1 2022-11-08T20:08:16.866Z,1667938096.866 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-08T20:08:16.867Z,1667938096.867 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-08T20:08:34.018Z,1667938114.018 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:08:34.286Z,1667938114.286 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:08:34.538Z,1667938114.538 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:08:44.634Z,1667938124.634 [DAT](FAULT): Buffer send receipt timeout failure. 2022-11-08T20:08:44.634Z,1667938124.634 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:08:44.887Z,1667938124.887 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:08:45.138Z,1667938125.138 [DAT](INFO): entering online mode 2022-11-08T20:08:45.390Z,1667938125.390 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:45.642Z,1667938125.642 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:45.894Z,1667938125.894 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:46.146Z,1667938126.146 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:46.398Z,1667938126.398 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:46.653Z,1667938126.653 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:46.902Z,1667938126.902 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:47.154Z,1667938127.154 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:47.406Z,1667938127.406 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:47.658Z,1667938127.658 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:47.910Z,1667938127.910 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:48.162Z,1667938128.162 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:48.414Z,1667938128.414 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:48.666Z,1667938128.666 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:48.918Z,1667938128.918 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:49.170Z,1667938129.170 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:49.422Z,1667938129.422 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:49.674Z,1667938129.674 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:49.926Z,1667938129.926 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:50.178Z,1667938130.178 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:50.430Z,1667938130.430 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:50.682Z,1667938130.682 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:50.934Z,1667938130.934 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:51.190Z,1667938131.190 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:51.443Z,1667938131.443 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:51.694Z,1667938131.694 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:51.946Z,1667938131.946 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:52.198Z,1667938132.198 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:52.450Z,1667938132.450 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:52.702Z,1667938132.702 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:52.954Z,1667938132.954 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:53.206Z,1667938133.206 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:53.458Z,1667938133.458 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:53.710Z,1667938133.710 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:53.962Z,1667938133.962 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:54.214Z,1667938134.214 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:54.466Z,1667938134.466 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:54.718Z,1667938134.718 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:54.970Z,1667938134.970 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:55.222Z,1667938135.222 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:55.474Z,1667938135.474 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:55.726Z,1667938135.726 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:55.978Z,1667938135.978 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:56.231Z,1667938136.231 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:56.482Z,1667938136.482 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:56.734Z,1667938136.734 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:56.986Z,1667938136.986 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:57.238Z,1667938137.238 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:57.490Z,1667938137.490 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:57.742Z,1667938137.742 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:57.994Z,1667938137.994 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:58.246Z,1667938138.246 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:58.498Z,1667938138.498 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:58.750Z,1667938138.750 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:59.002Z,1667938139.002 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:59.254Z,1667938139.254 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:59.507Z,1667938139.507 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:08:59.758Z,1667938139.758 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:00.010Z,1667938140.010 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:00.262Z,1667938140.262 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:00.262Z,1667938140.262 [DAT](FAULT): failed to enter online mode 2022-11-08T20:09:00.262Z,1667938140.262 [DAT](FAULT): Failure returning to online mode 2022-11-08T20:09:00.262Z,1667938140.262 [DAT] Communications Fault, FailCount= 3 2022-11-08T20:09:00.262Z,1667938140.262 [DAT](ERROR): Communications Fault 2022-11-08T20:09:00.525Z,1667938140.525 [CBIT](ERROR): Communications Fault in component: DAT 2022-11-08T20:09:00.666Z,1667938140.666 [DAT](INFO): Powering down 2022-11-08T20:09:01.719Z,1667938141.719 [CBIT](INFO): Clearing failed state for component DAT 2022-11-08T20:09:01.720Z,1667938141.720 [DAT] No Fault, FailCount= 3 2022-11-08T20:09:03.714Z,1667938143.714 [DAT](INFO): Powering up 2022-11-08T20:09:03.714Z,1667938143.714 [DAT](DEBUG): Initializing DAT. 2022-11-08T20:09:18.836Z,1667938158.836 [DAT](INFO): commRate: 800 2022-11-08T20:09:20.902Z,1667938160.902 [DAT](INFO): entering command mode 2022-11-08T20:09:21.103Z,1667938161.103 [DAT](INFO): setting verbose to 3 2022-11-08T20:09:21.355Z,1667938161.355 [DAT](INFO): set verbose to 3 2022-11-08T20:09:21.355Z,1667938161.355 [DAT](INFO): setting DatVerbose to 27440 2022-11-08T20:09:21.607Z,1667938161.607 [DAT](INFO): set DatVerbose to 27440 2022-11-08T20:09:21.608Z,1667938161.608 [DAT](INFO): setting transmit power to 8 2022-11-08T20:09:21.861Z,1667938161.861 [DAT](INFO): set transmit power to 8 2022-11-08T20:09:21.861Z,1667938161.861 [DAT](INFO): setting local address to 10 2022-11-08T20:09:22.111Z,1667938162.111 [DAT](INFO): set local address to 10 2022-11-08T20:09:22.112Z,1667938162.112 [DAT](INFO): Setting time to: 20:9:22 And date to:11/8/2022 2022-11-08T20:09:22.363Z,1667938162.363 [DAT](INFO): Local DAT time set to Tue Nov 8, 2022 20:09:22 2022-11-08T20:09:22.364Z,1667938162.364 [DAT](INFO): setting remote address to 1 2022-11-08T20:09:22.615Z,1667938162.615 [DAT](INFO): set remote address to 1 2022-11-08T20:09:22.616Z,1667938162.616 [DAT](INFO): entering online mode 2022-11-08T20:09:22.868Z,1667938162.868 [DAT](INFO): commRate: 800 2022-11-08T20:09:22.868Z,1667938162.868 [DAT](INFO): online mode acknowledged 2022-11-08T20:09:22.869Z,1667938162.869 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:09:32.954Z,1667938172.954 [DAT](FAULT): Buffer send receipt timeout failure. 2022-11-08T20:09:32.954Z,1667938172.954 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER 2022-11-08T20:09:33.206Z,1667938173.206 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-08T20:09:33.458Z,1667938173.458 [DAT](INFO): entering online mode 2022-11-08T20:09:33.711Z,1667938173.711 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:33.962Z,1667938173.962 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:34.214Z,1667938174.214 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:34.466Z,1667938174.466 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:34.718Z,1667938174.718 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:34.970Z,1667938174.970 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:35.222Z,1667938175.222 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:35.474Z,1667938175.474 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:35.726Z,1667938175.726 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:35.979Z,1667938175.979 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:36.250Z,1667938176.250 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:36.510Z,1667938176.510 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:36.762Z,1667938176.762 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:37.014Z,1667938177.014 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:37.270Z,1667938177.270 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:37.522Z,1667938177.522 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:37.782Z,1667938177.782 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:38.034Z,1667938178.034 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:38.286Z,1667938178.286 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:38.538Z,1667938178.538 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:38.790Z,1667938178.790 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:39.043Z,1667938179.043 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:39.294Z,1667938179.294 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:39.546Z,1667938179.546 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:39.798Z,1667938179.798 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:40.050Z,1667938180.050 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:40.302Z,1667938180.302 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:40.554Z,1667938180.554 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:40.806Z,1667938180.806 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:41.058Z,1667938181.058 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:41.310Z,1667938181.310 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:41.562Z,1667938181.562 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:41.814Z,1667938181.814 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:42.066Z,1667938182.066 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:42.318Z,1667938182.318 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:42.570Z,1667938182.570 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:42.822Z,1667938182.822 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:43.074Z,1667938183.074 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:43.326Z,1667938183.326 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:43.578Z,1667938183.578 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:43.838Z,1667938183.838 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:44.090Z,1667938184.090 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:44.342Z,1667938184.342 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:44.594Z,1667938184.594 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:44.846Z,1667938184.846 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:45.098Z,1667938185.098 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:45.351Z,1667938185.351 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:45.602Z,1667938185.602 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:45.854Z,1667938185.854 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:46.106Z,1667938186.106 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:46.358Z,1667938186.358 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:46.610Z,1667938186.610 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:46.864Z,1667938186.864 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:47.114Z,1667938187.114 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:47.366Z,1667938187.366 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:47.619Z,1667938187.619 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:47.870Z,1667938187.870 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:48.122Z,1667938188.122 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:48.374Z,1667938188.374 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:48.626Z,1667938188.626 [DAT](DEBUG): checking for online mode acknowledgment 2022-11-08T20:09:48.627Z,1667938188.627 [DAT](FAULT): failed to enter online mode 2022-11-08T20:09:48.627Z,1667938188.627 [DAT](FAULT): Failure returning to online mode 2022-11-08T20:09:48.627Z,1667938188.627 [DAT] Communications Fault, FailCount= 4 2022-11-08T20:09:48.627Z,1667938188.627 [DAT](ERROR): Communications Fault 2022-11-08T20:09:48.652Z,1667938188.652 [CBIT](ERROR): Communications Fault in component: DAT 2022-11-08T20:09:49.030Z,1667938189.030 [DAT](INFO): Powering down 2022-11-08T20:09:50.293Z,1667938190.293 [CBIT](INFO): Clearing failed state for component DAT 2022-11-08T20:09:50.293Z,1667938190.293 [DAT] No Fault, FailCount= 4 2022-11-08T20:09:52.082Z,1667938192.082 [DAT](INFO): Powering up 2022-11-08T20:09:52.082Z,1667938192.082 [DAT](DEBUG): Initializing DAT. 2022-11-08T20:10:07.208Z,1667938207.208 [DAT](INFO): commRate: 800 2022-11-08T20:10:09.270Z,1667938209.270 [DAT](INFO): entering command mode 2022-11-08T20:10:09.471Z,1667938209.471 [DAT](INFO): setting verbose to 3 2022-11-08T20:10:09.724Z,1667938209.724 [DAT](INFO): set verbose to 3 2022-11-08T20:10:09.724Z,1667938209.724 [DAT](INFO): setting DatVerbose to 27440 2022-11-08T20:10:09.975Z,1667938209.975 [DAT](INFO): set DatVerbose to 27440 2022-11-08T20:10:09.976Z,1667938209.976 [DAT](INFO): setting transmit power to 8 2022-11-08T20:10:10.227Z,1667938210.227 [DAT](INFO): set transmit power to 8 2022-11-08T20:10:10.227Z,1667938210.227 [DAT](INFO): setting local address to 10 2022-11-08T20:10:10.479Z,1667938210.479 [DAT](INFO): set local address to 10 2022-11-08T20:10:10.480Z,1667938210.480 [DAT](INFO): Setting time to: 20:10:10 And date to:11/8/2022 2022-11-08T20:10:10.731Z,1667938210.731 [DAT](INFO): Local DAT time set to Tue Nov 8, 2022 20:10:10 2022-11-08T20:10:10.732Z,1667938210.732 [DAT](INFO): setting remote address to 1 2022-11-08T20:10:10.983Z,1667938210.983 [DAT](INFO): set remote address to 1 2022-11-08T20:10:10.984Z,1667938210.984 [DAT](INFO): entering online mode 2022-11-08T20:10:11.236Z,1667938211.236 [DAT](INFO): commRate: 800 2022-11-08T20:10:11.236Z,1667938211.236 [DAT](INFO): online mode acknowledged 2022-11-08T20:10:11.236Z,1667938211.236 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-08T20:10:17.415Z,1667938217.415 [CommandExec](IMPORTANT): got command restart system 2022-11-08T20:10:19.478Z,1667938219.478 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2022-11-08T20:10:19.478Z,1667938219.478 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:19.479Z,1667938219.479 [CommandExec](INFO): Uninitializing the command executive. 2022-11-08T20:10:19.479Z,1667938219.479 [CommandExec](INFO): Uninitializing the command scheduler. 2022-11-08T20:10:19.479Z,1667938219.479 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.482Z,1667938219.482 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-11-08T20:10:19.482Z,1667938219.482 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-11-08T20:10:19.482Z,1667938219.482 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.483Z,1667938219.483 [NavChartDb](INFO): Join timeout helper Thread ID is 991 2022-11-08T20:10:19.542Z,1667938219.542 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:19.542Z,1667938219.542 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.543Z,1667938219.543 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-11-08T20:10:19.543Z,1667938219.543 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.543Z,1667938219.543 [DAT](INFO): Join timeout helper Thread ID is 992 2022-11-08T20:10:19.550Z,1667938219.550 [DAT](INFO): Powering down 2022-11-08T20:10:19.627Z,1667938219.627 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:19.627Z,1667938219.627 [DAT](INFO): Powering down 2022-11-08T20:10:19.628Z,1667938219.628 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.634Z,1667938219.634 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-11-08T20:10:19.634Z,1667938219.634 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.634Z,1667938219.634 [Radio_Surface](INFO): Join timeout helper Thread ID is 993 2022-11-08T20:10:19.682Z,1667938219.682 [Radio_Surface](INFO): Powering down 2022-11-08T20:10:19.683Z,1667938219.683 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:19.683Z,1667938219.683 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.702Z,1667938219.702 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-11-08T20:10:19.702Z,1667938219.702 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:19.702Z,1667938219.702 [Onboard](INFO): Join timeout helper Thread ID is 994 2022-11-08T20:10:19.842Z,1667938219.842 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-11-08T20:10:21.510Z,1667938221.510 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:21.510Z,1667938221.510 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:21.522Z,1667938221.522 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-11-08T20:10:21.522Z,1667938221.522 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:21.522Z,1667938221.522 [DataOverHttps](INFO): Join timeout helper Thread ID is 995 2022-11-08T20:10:21.850Z,1667938221.850 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:21.850Z,1667938221.850 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:21.871Z,1667938221.871 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-11-08T20:10:21.871Z,1667938221.871 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:21.871Z,1667938221.871 [BackseatComponent](INFO): Join timeout helper Thread ID is 996 2022-11-08T20:10:22.050Z,1667938222.050 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:22.050Z,1667938222.050 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.070Z,1667938222.070 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-11-08T20:10:22.071Z,1667938222.071 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.071Z,1667938222.071 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 997 2022-11-08T20:10:22.454Z,1667938222.454 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:22.454Z,1667938222.454 [WetLabsBB2FL](INFO): Powering down 2022-11-08T20:10:22.455Z,1667938222.455 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.474Z,1667938222.474 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-11-08T20:10:22.474Z,1667938222.474 [logger ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.475Z,1667938222.475 [logger](INFO): Join timeout helper Thread ID is 998 2022-11-08T20:10:22.478Z,1667938222.478 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:22.478Z,1667938222.478 [logger ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.494Z,1667938222.494 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-11-08T20:10:22.494Z,1667938222.494 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.495Z,1667938222.495 [CommandLine](INFO): Join timeout helper Thread ID is 999 2022-11-08T20:10:22.582Z,1667938222.582 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:22.582Z,1667938222.582 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.594Z,1667938222.594 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-11-08T20:10:22.594Z,1667938222.594 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.595Z,1667938222.595 [CommandExec](INFO): Join timeout helper Thread ID is 1000 2022-11-08T20:10:22.596Z,1667938222.596 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-11-08T20:10:22.596Z,1667938222.596 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:22.597Z,1667938222.597 [controlThread](INFO): Join timeout helper Thread ID is 1001 2022-11-08T20:10:22.942Z,1667938222.942 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T20:10:22.942Z,1667938222.942 [controlThread](DEBUG): Uninitializing ControlThread 2022-11-08T20:10:22.942Z,1667938222.942 [AHRS_M2](INFO): Powering down 2022-11-08T20:10:23.254Z,1667938223.254 [MultiRay](INFO): Powering down. 2022-11-08T20:10:23.255Z,1667938223.255 [NAL9602](INFO): Powering down 2022-11-08T20:10:23.257Z,1667938223.257 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-11-08T20:10:23.257Z,1667938223.257 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-11-08T20:10:23.258Z,1667938223.258 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-11-08T20:10:23.259Z,1667938223.259 [MissionManager](INFO): Uninitializing Mission Default 2022-11-08T20:10:23.259Z,1667938223.259 [Default] Stopped 2022-11-08T20:10:23.259Z,1667938223.259 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T20:10:23.259Z,1667938223.259 [Default:B.GoToSurface] Stopped 2022-11-08T20:10:23.259Z,1667938223.259 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T20:10:23.259Z,1667938223.259 [Default:CheckIn] Stopped 2022-11-08T20:10:23.259Z,1667938223.259 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-08T20:10:23.259Z,1667938223.259 [Default:CheckIn:Read_GPS] Stopped 2022-11-08T20:10:23.262Z,1667938223.262 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-11-08T20:10:23.263Z,1667938223.263 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-11-08T20:10:23.263Z,1667938223.263 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-11-08T20:10:23.263Z,1667938223.263 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-11-08T20:10:23.264Z,1667938223.264 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-11-08T20:10:23.264Z,1667938223.264 [BuoyancyServo](INFO): Powering down 2022-11-08T20:10:23.278Z,1667938223.278 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-11-08T20:10:23.278Z,1667938223.278 [ElevatorServo](INFO): Powering down 2022-11-08T20:10:23.279Z,1667938223.279 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-11-08T20:10:23.279Z,1667938223.279 [MassServo](INFO): Powering down 2022-11-08T20:10:23.280Z,1667938223.280 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-11-08T20:10:23.280Z,1667938223.280 [RudderServo](INFO): Powering down 2022-11-08T20:10:23.281Z,1667938223.281 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-11-08T20:10:23.281Z,1667938223.281 [ThrusterHE](INFO): Powering down 2022-11-08T20:10:23.282Z,1667938223.282 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-11-08T20:10:23.282Z,1667938223.282 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-11-08T20:10:23.283Z,1667938223.283 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-11-08T20:10:23.283Z,1667938223.283 [CBIT](DEBUG): Powering off loads. 2022-11-08T20:10:23.294Z,1667938223.294 [CBIT](DEBUG): Disabling WDT. 2022-11-08T20:10:23.305Z,1667938223.305 [CBIT](DEBUG): Opening all GF detection circuits. 2022-11-08T20:10:23.307Z,1667938223.307 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.339Z,1667938223.339 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.389Z,1667938223.389 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.394Z,1667938223.394 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.397Z,1667938223.397 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.404Z,1667938223.404 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.449Z,1667938223.449 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.496Z,1667938223.496 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-08T20:10:23.558Z,1667938223.558 [logger ThreadHandler](INFO): Thread cancelled.