2022-11-09T18:40:09.801Z,1668019209.801 [Supervisor](DEBUG): Initializing supervisor.
2022-11-09T18:40:09.806Z,1668019209.806 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-11-09T18:40:09.807Z,1668019209.807 [SyncHandler](INFO): Protected caller Thread ID is 5727
2022-11-09T18:40:09.807Z,1668019209.807 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-11-09T18:40:09.809Z,1668019209.809 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-11-09T18:40:09.809Z,1668019209.809 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5728
2022-11-09T18:40:09.814Z,1668019209.814 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-11-09T18:40:09.832Z,1668019209.832 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-11-09T18:40:09.833Z,1668019209.833 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-11-09T18:40:09.833Z,1668019209.833 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5729
2022-11-09T18:40:09.838Z,1668019209.838 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-11-09T18:40:09.839Z,1668019209.839 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-11-09T18:40:09.839Z,1668019209.839 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5730
2022-11-09T18:40:09.841Z,1668019209.841 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-11-09T18:40:09.842Z,1668019209.842 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-11-09T18:40:09.843Z,1668019209.843 [logger ThreadHandler](INFO): Protected caller Thread ID is 5731
2022-11-09T18:40:09.847Z,1668019209.847 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-11-09T18:40:09.847Z,1668019209.847 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-11-09T18:40:09.849Z,1668019209.849 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-11-09T18:40:10.260Z,1668019210.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-11-09T18:40:10.261Z,1668019210.261 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-11-09T18:40:10.468Z,1668019210.468 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-11-09T18:40:10.469Z,1668019210.469 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-11-09T18:40:10.644Z,1668019210.644 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-11-09T18:40:10.645Z,1668019210.645 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-11-09T18:40:10.749Z,1668019210.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-11-09T18:40:10.750Z,1668019210.750 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-11-09T18:40:11.102Z,1668019211.102 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-11-09T18:40:11.103Z,1668019211.103 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-11-09T18:40:11.410Z,1668019211.410 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-11-09T18:40:11.410Z,1668019211.410 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-11-09T18:40:11.505Z,1668019211.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-11-09T18:40:11.505Z,1668019211.505 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-11-09T18:40:11.716Z,1668019211.716 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-11-09T18:40:11.717Z,1668019211.717 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-11-09T18:40:12.207Z,1668019212.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-11-09T18:40:12.208Z,1668019212.208 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-11-09T18:40:12.549Z,1668019212.549 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-11-09T18:40:12.549Z,1668019212.549 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-11-09T18:40:12.629Z,1668019212.629 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-11-09T18:40:12.833Z,1668019212.833 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-11-09T18:40:12.833Z,1668019212.833 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-11-09T18:40:12.966Z,1668019212.966 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-11-09T18:40:12.967Z,1668019212.967 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-11-09T18:40:13.717Z,1668019213.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-11-09T18:40:13.718Z,1668019213.718 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-11-09T18:40:13.812Z,1668019213.812 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-11-09T18:40:14.643Z,1668019214.643 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-11-09T18:40:14.645Z,1668019214.645 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2022-11-09T18:40:14.646Z,1668019214.646 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2022-11-09T18:40:14.818Z,1668019214.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2022-11-09T18:40:14.910Z,1668019214.910 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2022-11-09T18:40:15.019Z,1668019215.019 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2022-11-09T18:40:15.118Z,1668019215.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2022-11-09T18:40:15.200Z,1668019215.200 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2022-11-09T18:40:15.284Z,1668019215.284 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2022-11-09T18:40:15.396Z,1668019215.396 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2022-11-09T18:40:15.492Z,1668019215.492 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2022-11-09T18:40:15.643Z,1668019215.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2022-11-09T18:40:15.903Z,1668019215.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-11-09T18:40:15.903Z,1668019215.903 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2022-11-09T18:40:15.996Z,1668019215.996 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2022-11-09T18:40:15.997Z,1668019215.997 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-11-09T18:40:16.009Z,1668019216.009 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-11-09T18:40:16.319Z,1668019216.319 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-11-09T18:40:16.320Z,1668019216.320 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-11-09T18:40:16.435Z,1668019216.435 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-11-09T18:40:16.435Z,1668019216.435 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-11-09T18:40:16.475Z,1668019216.475 [DeadReckonUsingSpeedCalculator] Loaded
2022-11-09T18:40:16.475Z,1668019216.475 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2022-11-09T18:40:16.489Z,1668019216.489 [NavChart] Loaded
2022-11-09T18:40:16.489Z,1668019216.489 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-11-09T18:40:16.495Z,1668019216.495 [UniversalFixResidualReporter] Loaded
2022-11-09T18:40:16.495Z,1668019216.495 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-11-09T18:40:16.495Z,1668019216.495 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-11-09T18:40:16.496Z,1668019216.496 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-11-09T18:40:16.506Z,1668019216.506 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-11-09T18:40:16.507Z,1668019216.507 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-11-09T18:40:16.668Z,1668019216.668 [PAR_Licor] Loaded
2022-11-09T18:40:16.669Z,1668019216.669 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-11-09T18:40:16.701Z,1668019216.701 [WetLabsBB2FL] Loaded
2022-11-09T18:40:16.701Z,1668019216.701 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-11-09T18:40:16.702Z,1668019216.702 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065A4E0
2022-11-09T18:40:16.703Z,1668019216.703 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5813
2022-11-09T18:40:16.703Z,1668019216.703 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-11-09T18:40:16.704Z,1668019216.704 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-11-09T18:40:16.755Z,1668019216.755 [VerticalControl](DEBUG): Construct VerticalControl.
2022-11-09T18:40:16.817Z,1668019216.817 [VerticalControl] Loaded
2022-11-09T18:40:16.817Z,1668019216.817 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-11-09T18:40:16.820Z,1668019216.820 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-11-09T18:40:16.862Z,1668019216.862 [HorizontalControl] Loaded
2022-11-09T18:40:16.862Z,1668019216.862 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-11-09T18:40:16.864Z,1668019216.864 [SpeedControl](DEBUG): Construct SpeedControl.
2022-11-09T18:40:16.868Z,1668019216.868 [SpeedControl] Loaded
2022-11-09T18:40:16.868Z,1668019216.868 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-11-09T18:40:16.871Z,1668019216.871 [LoopControl](DEBUG): Construct LoopControl.
2022-11-09T18:40:16.871Z,1668019216.871 [LoopControl] Loaded
2022-11-09T18:40:16.871Z,1668019216.871 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-11-09T18:40:16.872Z,1668019216.872 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-11-09T18:40:16.873Z,1668019216.873 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-11-09T18:40:16.922Z,1668019216.922 [DepthRateCalculator] Loaded
2022-11-09T18:40:16.923Z,1668019216.923 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-11-09T18:40:16.928Z,1668019216.928 [PitchRateCalculator] Loaded
2022-11-09T18:40:16.928Z,1668019216.928 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-11-09T18:40:16.937Z,1668019216.937 [SpeedCalculator] Loaded
2022-11-09T18:40:16.938Z,1668019216.938 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-11-09T18:40:16.942Z,1668019216.942 [YawRateCalculator] Loaded
2022-11-09T18:40:16.942Z,1668019216.942 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-11-09T18:40:16.961Z,1668019216.961 [ElevatorOffsetCalculator] Loaded
2022-11-09T18:40:16.961Z,1668019216.961 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-11-09T18:40:16.962Z,1668019216.962 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-11-09T18:40:16.962Z,1668019216.962 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-11-09T18:40:17.056Z,1668019217.056 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-11-09T18:40:17.057Z,1668019217.057 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-11-09T18:40:17.117Z,1668019217.117 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-11-09T18:40:17.118Z,1668019217.118 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-11-09T18:40:17.244Z,1668019217.244 [BuoyancyServo] Loaded
2022-11-09T18:40:17.244Z,1668019217.244 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-11-09T18:40:17.264Z,1668019217.264 [ElevatorServo] Loaded
2022-11-09T18:40:17.265Z,1668019217.265 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-11-09T18:40:17.284Z,1668019217.284 [MassServo] Loaded
2022-11-09T18:40:17.284Z,1668019217.284 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-11-09T18:40:17.303Z,1668019217.303 [RudderServo] Loaded
2022-11-09T18:40:17.303Z,1668019217.303 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-11-09T18:40:17.318Z,1668019217.318 [ThrusterHE] Loaded
2022-11-09T18:40:17.318Z,1668019217.318 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-11-09T18:40:17.319Z,1668019217.319 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-11-09T18:40:17.319Z,1668019217.319 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-11-09T18:40:17.475Z,1668019217.475 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-11-09T18:40:17.475Z,1668019217.475 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-11-09T18:40:17.900Z,1668019217.900 [AHRS_M2] Loaded
2022-11-09T18:40:17.900Z,1668019217.900 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-11-09T18:40:17.935Z,1668019217.935 [BackseatComponent] Loaded
2022-11-09T18:40:17.936Z,1668019217.936 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-11-09T18:40:17.937Z,1668019217.937 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0
2022-11-09T18:40:17.937Z,1668019217.937 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 5814
2022-11-09T18:40:17.940Z,1668019217.940 [LcmUniversalReporter] Loaded
2022-11-09T18:40:17.940Z,1668019217.940 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-11-09T18:40:18.769Z,1668019218.769 [BPC1] Loaded
2022-11-09T18:40:18.769Z,1668019218.769 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-11-09T18:40:18.843Z,1668019218.843 [DataOverHttps] Loaded
2022-11-09T18:40:18.844Z,1668019218.844 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-11-09T18:40:18.845Z,1668019218.845 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0
2022-11-09T18:40:18.845Z,1668019218.845 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5815
2022-11-09T18:40:18.866Z,1668019218.866 [Depth_Keller] Loaded
2022-11-09T18:40:18.867Z,1668019218.867 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-11-09T18:40:18.872Z,1668019218.872 [DropWeight] Loaded
2022-11-09T18:40:18.872Z,1668019218.872 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-11-09T18:40:18.891Z,1668019218.891 [MultiRay] Loaded
2022-11-09T18:40:18.892Z,1668019218.892 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2022-11-09T18:40:18.955Z,1668019218.955 [NAL9602] Loaded
2022-11-09T18:40:18.955Z,1668019218.955 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-11-09T18:40:18.986Z,1668019218.986 [Onboard] Loaded
2022-11-09T18:40:18.987Z,1668019218.987 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-11-09T18:40:18.988Z,1668019218.988 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0
2022-11-09T18:40:18.988Z,1668019218.988 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5816
2022-11-09T18:40:18.994Z,1668019218.994 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2022-11-09T18:40:19.006Z,1668019219.006 [PowerOnly] Loaded
2022-11-09T18:40:19.006Z,1668019219.006 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-11-09T18:40:19.018Z,1668019219.018 [Power24vConverter] Loaded
2022-11-09T18:40:19.018Z,1668019219.018 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-11-09T18:40:19.032Z,1668019219.032 [Radio_Surface] Loaded
2022-11-09T18:40:19.032Z,1668019219.032 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-11-09T18:40:19.033Z,1668019219.033 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0
2022-11-09T18:40:19.034Z,1668019219.034 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5817
2022-11-09T18:40:19.262Z,1668019219.262 [DAT] Loaded
2022-11-09T18:40:19.263Z,1668019219.263 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-11-09T18:40:19.264Z,1668019219.264 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B154E0
2022-11-09T18:40:19.264Z,1668019219.264 [DAT ThreadHandler](INFO): Protected caller Thread ID is 5818
2022-11-09T18:40:19.265Z,1668019219.265 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-11-09T18:40:19.265Z,1668019219.265 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-11-09T18:40:19.648Z,1668019219.648 [SBIT](DEBUG): Construct Startup Built In Test.
2022-11-09T18:40:19.659Z,1668019219.659 [SBIT] Loaded
2022-11-09T18:40:19.659Z,1668019219.659 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-11-09T18:40:19.665Z,1668019219.665 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-11-09T18:40:19.679Z,1668019219.679 [IBIT] Loaded
2022-11-09T18:40:19.679Z,1668019219.679 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-11-09T18:40:19.685Z,1668019219.685 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-11-09T18:40:19.791Z,1668019219.791 [CBIT] Loaded
2022-11-09T18:40:19.791Z,1668019219.791 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-11-09T18:40:19.791Z,1668019219.791 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-11-09T18:40:19.792Z,1668019219.792 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-11-09T18:40:19.819Z,1668019219.819 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-11-09T18:40:19.826Z,1668019219.826 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-11-09T18:40:19.829Z,1668019219.829 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-11-09T18:40:19.840Z,1668019219.840 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-11-09T18:40:19.841Z,1668019219.841 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA34E0
2022-11-09T18:40:19.842Z,1668019219.842 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5819
2022-11-09T18:40:19.846Z,1668019219.846 [Supervisor](INFO): Main Thread ID is 5393
2022-11-09T18:40:19.846Z,1668019219.846 [Supervisor](DEBUG): Running supervisor.
2022-11-09T18:40:19.847Z,1668019219.847 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5820
2022-11-09T18:40:19.847Z,1668019219.847 [CommandExec](INFO): Initializing the command executive.
2022-11-09T18:40:19.849Z,1668019219.849 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5821
2022-11-09T18:40:19.851Z,1668019219.851 [controlThread ThreadHandler](INFO): Handler Thread ID is 5822
2022-11-09T18:40:19.851Z,1668019219.851 [controlThread](DEBUG): Initializing ControlThread
2022-11-09T18:40:19.853Z,1668019219.853 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-11-09T18:40:19.853Z,1668019219.853 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-11-09T18:40:19.854Z,1668019219.854 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-11-09T18:40:19.857Z,1668019219.857 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-11-09T18:40:19.858Z,1668019219.858 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-11-09T18:40:19.859Z,1668019219.859 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-11-09T18:40:19.859Z,1668019219.859 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-11-09T18:40:19.860Z,1668019219.860 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-11-09T18:40:19.860Z,1668019219.860 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-11-09T18:40:19.861Z,1668019219.861 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-11-09T18:40:19.861Z,1668019219.861 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-11-09T18:40:19.862Z,1668019219.862 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-11-09T18:40:19.870Z,1668019219.870 [SBIT](INFO): Initialize SBIT Component.
2022-11-09T18:40:19.871Z,1668019219.871 [SBIT](IMPORTANT): git: 2022-10-11-49-gb44faf3dc
2022-11-09T18:40:19.871Z,1668019219.871 [SBIT](INFO): git hash: b44faf3dc92774180e7da8d3246e288394a00694
2022-11-09T18:40:19.871Z,1668019219.871 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-11-09T18:40:19.873Z,1668019219.873 [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-09T18:40:19.874Z,1668019219.874 [SBIT](INFO): Beginning SBIT in 109.000000 seconds.
2022-11-09T18:40:19.874Z,1668019219.874 [IBIT](INFO): Initialize IBIT Component.
2022-11-09T18:40:19.875Z,1668019219.875 [CBIT](DEBUG): Initialize CBIT Component.
2022-11-09T18:40:19.876Z,1668019219.876 [logger ThreadHandler](INFO): Handler Thread ID is 5823
2022-11-09T18:40:19.888Z,1668019219.888 [CBIT](DEBUG): Initialized mux pins.
2022-11-09T18:40:19.888Z,1668019219.888 [CBIT](DEBUG): Initializing the watchdog timer.
2022-11-09T18:40:19.897Z,1668019219.897 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5824
2022-11-09T18:40:19.901Z,1668019219.901 [WetLabsBB2FL](INFO): Powering up
2022-11-09T18:40:19.902Z,1668019219.902 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 5826
2022-11-09T18:40:19.909Z,1668019219.909 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5827
2022-11-09T18:40:19.910Z,1668019219.910 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-11-09T18:40:19.912Z,1668019219.912 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-11-09T18:40:19.913Z,1668019219.913 [CBIT](DEBUG): Initializing heartbeat.
2022-11-09T18:40:19.921Z,1668019219.921 [Onboard ThreadHandler](INFO): Handler Thread ID is 5828
2022-11-09T18:40:19.938Z,1668019219.938 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5829
2022-11-09T18:40:19.957Z,1668019219.957 [DAT ThreadHandler](INFO): Handler Thread ID is 5830
2022-11-09T18:40:19.957Z,1668019219.957 [DAT](INFO): Powering up
2022-11-09T18:40:19.958Z,1668019219.958 [DAT](DEBUG): Initializing DAT.
2022-11-09T18:40:19.961Z,1668019219.961 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5832
2022-11-09T18:40:19.964Z,1668019219.964 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-11-09T18:40:19.964Z,1668019219.964 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-11-09T18:40:19.965Z,1668019219.965 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-11-09T18:40:19.965Z,1668019219.965 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-11-09T18:40:19.965Z,1668019219.965 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-11-09T18:40:19.965Z,1668019219.965 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-11-09T18:40:19.965Z,1668019219.965 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-11-09T18:40:19.965Z,1668019219.965 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-11-09T18:40:19.984Z,1668019219.984 [CBIT](DEBUG): Deactivating GF circuits.
2022-11-09T18:40:19.984Z,1668019219.984 [CBIT](DEBUG): Deactivating emergency mode.
2022-11-09T18:40:20.020Z,1668019220.020 [CBIT](DEBUG): Backplane powered.
2022-11-09T18:40:20.021Z,1668019220.021 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-11-09T18:40:20.034Z,1668019220.034 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-11-09T18:40:20.061Z,1668019220.061 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2022-11-09T18:40:20.062Z,1668019220.062 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-11-09T18:40:20.132Z,1668019220.132 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-11-09T18:40:20.133Z,1668019220.133 [Default:A.Wait](DEBUG): Construct Wait.
2022-11-09T18:40:20.135Z,1668019220.135 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-11-09T18:40:20.195Z,1668019220.195 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-11-09T18:40:20.198Z,1668019220.198 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-11-09T18:40:20.230Z,1668019220.230 [Default:E.Execute](DEBUG): Construct Execute.
2022-11-09T18:40:20.250Z,1668019220.250 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2022-11-09T18:40:20.255Z,1668019220.255 [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-09T18:40:20.279Z,1668019220.279 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-11-09T18:40:20.344Z,1668019220.344 [Radio_Surface](INFO): Powering up
2022-11-09T18:40:20.351Z,1668019220.351 [MultiRay](INFO): Powering up MultiRay Lights
2022-11-09T18:40:20.393Z,1668019220.393 [Power24vConverter](INFO): Powering up.
2022-11-09T18:40:20.433Z,1668019220.433 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-11-09T18:40:20.441Z,1668019220.441 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-11-09T18:40:20.442Z,1668019220.442 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-11-09T18:40:20.449Z,1668019220.449 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-11-09T18:40:20.450Z,1668019220.450 [MassServo](DEBUG): Initializing EZServoServo.
2022-11-09T18:40:20.457Z,1668019220.457 [MassServo](DEBUG): Initializing MassServo.
2022-11-09T18:40:20.458Z,1668019220.458 [RudderServo](DEBUG): Initializing EZServoServo.
2022-11-09T18:40:20.465Z,1668019220.465 [RudderServo](DEBUG): Initializing RudderServo.
2022-11-09T18:40:20.466Z,1668019220.466 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-11-09T18:40:20.473Z,1668019220.473 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-11-09T18:40:20.725Z,1668019220.725 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2022-11-09T18:40:20.726Z,1668019220.726 [DropWeight] Hardware Fault, FailCount= 1
2022-11-09T18:40:20.726Z,1668019220.726 [DropWeight](ERROR): Hardware Fault
2022-11-09T18:40:20.753Z,1668019220.753 [MultiRay](IMPORTANT): All lights off
2022-11-09T18:40:20.800Z,1668019220.800 [CommandExec](FAULT): Scheduling is paused
2022-11-09T18:40:20.808Z,1668019220.808 [CBIT](INFO): Critical error at 20221109T184020
2022-11-09T18:40:20.808Z,1668019220.808 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2022-11-09T18:40:20.811Z,1668019220.811 [CBIT](ERROR): Hardware Fault in component: DropWeight
2022-11-09T18:40:20.811Z,1668019220.811 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2022-11-09T18:40:21.396Z,1668019221.396 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-11-09T18:40:21.396Z,1668019221.396 [RudderServo](FAULT): Rudder failed to initialize
2022-11-09T18:40:21.396Z,1668019221.396 [RudderServo] Communications Fault, FailCount= 1
2022-11-09T18:40:21.397Z,1668019221.397 [RudderServo](ERROR): Communications Fault
2022-11-09T18:40:21.398Z,1668019221.398 [CBIT](INFO): Critical error at 20221109T184020
2022-11-09T18:40:21.401Z,1668019221.401 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-11-09T18:40:21.861Z,1668019221.861 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-11-09T18:40:21.861Z,1668019221.861 [RudderServo](INFO): Powering down
2022-11-09T18:40:22.305Z,1668019222.305 [RudderServo](DEBUG): Initializing EZServoServo.
2022-11-09T18:40:22.425Z,1668019222.425 [RudderServo](DEBUG): Initializing RudderServo.
2022-11-09T18:40:22.429Z,1668019222.429 [CBIT](INFO): Clearing failed state for component RudderServo
2022-11-09T18:40:22.429Z,1668019222.429 [RudderServo] No Fault, FailCount= 1
2022-11-09T18:40:22.512Z,1668019222.512 [WetLabsBB2FL](INFO): Powering down
2022-11-09T18:40:26.085Z,1668019226.085 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-11-09T18:40:34.831Z,1668019234.831 [DAT](INFO): commRate: 800
2022-11-09T18:40:36.896Z,1668019236.896 [DAT](INFO): entering command mode
2022-11-09T18:40:37.098Z,1668019237.098 [DAT](INFO): setting verbose to 3
2022-11-09T18:40:37.350Z,1668019237.350 [DAT](INFO): set verbose to 3
2022-11-09T18:40:37.350Z,1668019237.350 [DAT](INFO): setting DatVerbose to 27440
2022-11-09T18:40:37.602Z,1668019237.602 [DAT](INFO): set DatVerbose to 27440
2022-11-09T18:40:37.602Z,1668019237.602 [DAT](INFO): setting transmit power to 8
2022-11-09T18:40:37.854Z,1668019237.854 [DAT](INFO): set transmit power to 8
2022-11-09T18:40:37.854Z,1668019237.854 [DAT](INFO): setting local address to 10
2022-11-09T18:40:38.106Z,1668019238.106 [DAT](INFO): set local address to 10
2022-11-09T18:40:38.107Z,1668019238.107 [DAT](INFO): Setting time to: 18:40:38 And date to:11/9/2022
2022-11-09T18:40:38.358Z,1668019238.358 [DAT](INFO): Local DAT time set to Wed Nov 9, 2022  18:40:38  

2022-11-09T18:40:49.062Z,1668019249.062 [NAL9602](INFO): Powering up NAL9602
2022-11-09T18:41:00.002Z,1668019260.002 [NAL9602](INFO): NAL9602 initialized
2022-11-09T18:42:09.486Z,1668019329.486 [SBIT](IMPORTANT): Beginning Startup BIT
2022-11-09T18:42:09.494Z,1668019329.494 [CBIT](IMPORTANT): Beginning ground fault scan
2022-11-09T18:42:20.422Z,1668019340.422 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.013436
CHAN A1 (24V): 0.000502
CHAN A2 (12V): -0.005444
CHAN A3 (5V): -0.002581
CHAN B0 (3.3V): -0.001287
CHAN B1 (3.15aV): -0.001417
CHAN B2 (3.15bV): -0.001452
CHAN B3 (GND): 0.000021
OPEN: 0.004664
Full Scale: +/- 1 mA
2022-11-09T18:42:47.967Z,1668019367.967 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004783
2022-11-09T18:43:03.088Z,1668019383.088 [CommandExec](IMPORTANT): got command show stack
2022-11-09T18:43:03.089Z,1668019383.089 [CommandExec](IMPORTANT): Behavior Stack:

2022-11-09T18:43:03.089Z,1668019383.089 [MissionManager](IMPORTANT): Mission loaded, but not running.
2022-11-09T18:43:03.685Z,1668019383.685 [SBIT](IMPORTANT): SBIT PASSED
2022-11-09T18:43:03.685Z,1668019383.685 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): BackseatComponent.needs24v=1 bool;

2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none;

2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): CBIT.gf24Offset=149 microampere;

2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter;

2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): Express none _.ayeris_disk_space;

2022-11-09T18:43:03.686Z,1668019383.686 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 250.000000 count;

2022-11-09T18:43:03.687Z,1668019383.687 [SBIT](IMPORTANT): Express none _.ayeris_particle_size;

2022-11-09T18:43:03.687Z,1668019383.687 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour;

2022-11-09T18:43:03.687Z,1668019383.687 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt;

2022-11-09T18:43:03.687Z,1668019383.687 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=210.367112 cubic_centimeter;

2022-11-09T18:43:03.687Z,1668019383.687 [SBIT](IMPORTANT): VerticalControl.massDefault=22.333859 millimeter;

2022-11-09T18:43:04.062Z,1668019384.062 [MissionManager](IMPORTANT): Started mission Startup
2022-11-09T18:43:04.062Z,1668019384.062 [Startup] Running Loop=1
2022-11-09T18:43:04.063Z,1668019384.063 [Startup](DEBUG): Aggregate::initialize Startup
2022-11-09T18:43:04.063Z,1668019384.063 [Startup:A.GoToSurface] Running Loop=1
2022-11-09T18:43:04.063Z,1668019384.063 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-11-09T18:43:04.063Z,1668019384.063 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-11-09T18:43:04.064Z,1668019384.064 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-11-09T18:43:04.068Z,1668019384.068 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-11-09T18:43:04.069Z,1668019384.069 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-11-09T18:43:04.069Z,1668019384.069 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-11-09T18:43:04.070Z,1668019384.070 [Startup:StartupSatComms] Running Loop=1
2022-11-09T18:43:04.071Z,1668019384.071 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-11-09T18:43:04.071Z,1668019384.071 [Startup:StartupSatComms:A] Running Loop=1
2022-11-09T18:43:04.430Z,1668019384.430 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-11-09T18:43:20.165Z,1668019400.165 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-11-09T18:43:20.165Z,1668019400.165 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-11-09T18:43:20.166Z,1668019400.166 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2022-11-09T18:43:20.166Z,1668019400.166 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-11-09T18:43:20.233Z,1668019400.233 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-11-09T18:43:20.233Z,1668019400.233 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-11-09T18:43:20.614Z,1668019400.614 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-11-09T18:43:20.614Z,1668019400.614 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-11-09T18:43:20.615Z,1668019400.615 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-11-09T18:43:20.615Z,1668019400.615 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2022-11-09T18:43:20.972Z,1668019400.972 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-11-09T18:44:04.201Z,1668019444.201 [Startup:StartupSatComms:A](INFO): Timed out from 2022-11-09T18:43:04.1Z
2022-11-09T18:44:04.201Z,1668019444.201 [Startup:StartupSatComms:A] Stopped
2022-11-09T18:44:04.201Z,1668019444.201 [Startup:StartupSatComms:B] Running Loop=1
2022-11-09T18:44:04.610Z,1668019444.610 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-11-09T18:44:06.341Z,1668019446.341 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2022-11-09T18:44:06.349Z,1668019446.349 [DAT](INFO): setting remote address to 1
2022-11-09T18:44:06.602Z,1668019446.602 [DAT](INFO): set remote address to 1
2022-11-09T18:44:06.603Z,1668019446.603 [DAT](INFO): entering online mode
2022-11-09T18:44:06.855Z,1668019446.855 [DAT](INFO): commRate: 800
2022-11-09T18:44:06.855Z,1668019446.855 [DAT](INFO): online mode acknowledged
2022-11-09T18:44:06.855Z,1668019446.855 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2022-11-09T18:44:10.130Z,1668019450.130 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2022-11-09T18:44:12.896Z,1668019452.896 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20221109T183056/Courier0004.lzma
2022-11-09T18:44:13.898Z,1668019453.898 [DataOverHttps](INFO): Moved sent file to Logs/20221109T183056/Courier0004.lzma.bak
2022-11-09T18:44:13.898Z,1668019453.898 [DataOverHttps](INFO): SBD MOMSN=17277812
2022-11-09T18:44:25.277Z,1668019465.277 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2022-11-09T18:44:26.909Z,1668019466.909 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2022-11-09T18:44:26.937Z,1668019466.937 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2022-11-09T18:44:30.194Z,1668019470.194 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2022-11-09T18:44:30.701Z,1668019470.701 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20221109T184009/Courier0000.lzma
2022-11-09T18:44:31.702Z,1668019471.702 [DataOverHttps](INFO): Moved sent file to Logs/20221109T184009/Courier0000.lzma.bak
2022-11-09T18:44:31.702Z,1668019471.702 [DataOverHttps](INFO): SBD MOMSN=17277814
2022-11-09T18:44:47.341Z,1668019487.341 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2022-11-09T18:44:48.609Z,1668019488.609 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2022-11-09T18:44:48.635Z,1668019488.635 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2022-11-09T18:44:48.981Z,1668019488.981 [Startup:StartupSatComms:B] Stopped
2022-11-09T18:44:48.981Z,1668019488.981 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-11-09T18:44:48.981Z,1668019488.981 [Startup:StartupSatComms] Stopped
2022-11-09T18:44:48.982Z,1668019488.982 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-11-09T18:44:48.982Z,1668019488.982 [Startup](INFO): Completed Startup
2022-11-09T18:44:48.982Z,1668019488.982 [MissionManager](INFO): Startup is completed.
2022-11-09T18:44:48.983Z,1668019488.983 [MissionManager](INFO): Uninitializing Mission Startup
2022-11-09T18:44:48.983Z,1668019488.983 [Startup] Stopped
2022-11-09T18:44:48.983Z,1668019488.983 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-11-09T18:44:48.983Z,1668019488.983 [Startup:A.GoToSurface] Stopped
2022-11-09T18:44:48.983Z,1668019488.983 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-11-09T18:44:49.269Z,1668019489.269 [DataOverHttps](INFO): Sending 1035 bytes from file Logs/20221109T003348/Express0001.lzma
2022-11-09T18:44:49.390Z,1668019489.390 [MissionManager](IMPORTANT): Started mission Default
2022-11-09T18:44:49.390Z,1668019489.390 [Default] Running Loop=1
2022-11-09T18:44:49.390Z,1668019489.390 [Default](DEBUG): Aggregate::initialize Default
2022-11-09T18:44:49.390Z,1668019489.390 [Default:B.GoToSurface] Running Loop=1
2022-11-09T18:44:49.391Z,1668019489.391 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-11-09T18:44:49.391Z,1668019489.391 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-11-09T18:44:49.391Z,1668019489.391 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-11-09T18:44:49.391Z,1668019489.391 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-11-09T18:44:49.392Z,1668019489.392 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-11-09T18:44:49.392Z,1668019489.392 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-11-09T18:44:49.393Z,1668019489.393 [Default:A.Wait] Running Loop=1
2022-11-09T18:44:49.393Z,1668019489.393 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:44:50.270Z,1668019490.270 [DataOverHttps](INFO): Moved sent file to Logs/20221109T003348/Express0001.lzma.bak
2022-11-09T18:44:50.270Z,1668019490.270 [DataOverHttps](INFO): SBD MOMSN=17277819
2022-11-09T18:44:51.886Z,1668019491.886 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2022-11-09T18:45:02.703Z,1668019502.703 [Default:A.Wait](INFO): Done Waiting.
2022-11-09T18:45:02.703Z,1668019502.703 [Default:A.Wait] Stopped
2022-11-09T18:45:02.703Z,1668019502.703 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:03.157Z,1668019503.157 [Default:CheckIn] Running Loop=1
2022-11-09T18:45:03.157Z,1668019503.157 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-11-09T18:45:03.157Z,1668019503.157 [Default:CheckIn:Read_GPS] Running Loop=1
2022-11-09T18:45:03.531Z,1668019503.531 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-11-09T18:45:07.430Z,1668019507.430 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_test.xml
2022-11-09T18:45:07.431Z,1668019507.431 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_test.xml
2022-11-09T18:45:07.490Z,1668019507.490 [MissionManager](INFO): DefineArg multiray_test.MissionTimeout = 5.000000 min
2022-11-09T18:45:07.512Z,1668019507.512 [MissionManager](INFO): DefineArg multiray_test.LightDuration = 5.000000 s
2022-11-09T18:45:07.515Z,1668019507.515 [MissionManager](INFO): DefineArg multiray_test.LightMode0 = 0.000000 count
2022-11-09T18:45:07.518Z,1668019507.518 [MissionManager](INFO): DefineArg multiray_test.LightMode1 = 1.000000 count
2022-11-09T18:45:07.521Z,1668019507.521 [MissionManager](INFO): DefineArg multiray_test.LightMode2 = 2.000000 count
2022-11-09T18:45:07.524Z,1668019507.524 [MissionManager](INFO): DefineArg multiray_test.EnabledMultiray = 1 bool
2022-11-09T18:45:07.580Z,1668019507.580 [multiray_test:C.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.583Z,1668019507.583 [multiray_test:E.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.591Z,1668019507.591 [multiray_test:G.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.606Z,1668019507.606 [multiray_test:I.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.625Z,1668019507.625 [multiray_test:K.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.628Z,1668019507.628 [multiray_test:M.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.640Z,1668019507.640 [multiray_test:O.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.647Z,1668019507.647 [multiray_test:Q.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.659Z,1668019507.659 [multiray_test:R.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.666Z,1668019507.666 [multiray_test:T.Wait](DEBUG): Construct Wait.
2022-11-09T18:45:07.685Z,1668019507.685 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>

<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Units="Tethys/Units"
         xmlns:Sample="Tethys/Sample"
         xmlns:Sensor="Tethys/Sensor"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd"
       Id="multiray_test">

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

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

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

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

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

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

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

    <Timeout Duration="MissionTimeout"/>



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


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

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode1"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode2"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>
    
    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode1"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode2"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode1"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode2"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

    <Assign><Sequence/><Sensor:MultiRay.lightModeCommand/><Arg Name="LightMode0"/></Assign>    
    <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="LightDuration"/></Setting>
            </Guidance:Wait>

</Mission>


2022-11-09T18:45:07.687Z,1668019507.687 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_test.xml
2022-11-09T18:45:07.975Z,1668019507.975 [Default] Stopped
2022-11-09T18:45:07.976Z,1668019507.976 [Default](DEBUG): Aggregate::uninitialize Default
2022-11-09T18:45:07.976Z,1668019507.976 [Default:B.GoToSurface] Stopped
2022-11-09T18:45:07.976Z,1668019507.976 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-11-09T18:45:07.976Z,1668019507.976 [Default:CheckIn] Stopped
2022-11-09T18:45:07.976Z,1668019507.976 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-11-09T18:45:07.976Z,1668019507.976 [Default:CheckIn:Read_GPS] Stopped
2022-11-09T18:45:07.976Z,1668019507.976 [MissionManager](IMPORTANT): Started mission multiray_test
2022-11-09T18:45:07.977Z,1668019507.977 [multiray_test] Running Loop=1
2022-11-09T18:45:07.977Z,1668019507.977 [multiray_test](DEBUG): Aggregate::initialize multiray_test
2022-11-09T18:45:07.977Z,1668019507.977 [multiray_test:A] Running Loop=1
2022-11-09T18:45:07.977Z,1668019507.977 [multiray_test:B] Running Loop=1
2022-11-09T18:45:07.977Z,1668019507.977 [multiray_test:B] Stopped
2022-11-09T18:45:07.978Z,1668019507.978 [multiray_test:C.Wait] Running Loop=1
2022-11-09T18:45:07.978Z,1668019507.978 [multiray_test:C.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:07.978Z,1668019507.978 [multiray_test:A] Running Loop=1
2022-11-09T18:45:07.978Z,1668019507.978 [multiray_test:A](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2022-11-09T18:45:09.041Z,1668019509.041 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2022-11-09T18:45:09.266Z,1668019509.266 [MultiRay](IMPORTANT): All lights off
2022-11-09T18:45:09.293Z,1668019509.293 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2022-11-09T18:45:09.547Z,1668019509.547 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2022-11-09T18:45:13.638Z,1668019513.638 [multiray_test:C.Wait](INFO): Done Waiting.
2022-11-09T18:45:13.639Z,1668019513.639 [multiray_test:C.Wait] Stopped
2022-11-09T18:45:13.639Z,1668019513.639 [multiray_test:C.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:13.639Z,1668019513.639 [multiray_test:D] Running Loop=1
2022-11-09T18:45:14.055Z,1668019514.055 [multiray_test:D] Stopped
2022-11-09T18:45:14.055Z,1668019514.055 [multiray_test:E.Wait] Running Loop=1
2022-11-09T18:45:14.055Z,1668019514.055 [multiray_test:E.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:15.301Z,1668019515.301 [MultiRay](INFO): Red lights on
2022-11-09T18:45:19.625Z,1668019519.625 [DAT](FAULT): Buffer send receipt timeout failure.
2022-11-09T18:45:19.625Z,1668019519.625 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2022-11-09T18:45:19.702Z,1668019519.702 [multiray_test:E.Wait](INFO): Done Waiting.
2022-11-09T18:45:19.703Z,1668019519.703 [multiray_test:E.Wait] Stopped
2022-11-09T18:45:19.703Z,1668019519.703 [multiray_test:E.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:19.703Z,1668019519.703 [multiray_test:F] Running Loop=1
2022-11-09T18:45:19.877Z,1668019519.877 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2022-11-09T18:45:20.090Z,1668019520.090 [multiray_test:F] Stopped
2022-11-09T18:45:20.091Z,1668019520.091 [multiray_test:G.Wait] Running Loop=1
2022-11-09T18:45:20.091Z,1668019520.091 [multiray_test:G.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:20.129Z,1668019520.129 [DAT](INFO): entering online mode
2022-11-09T18:45:20.381Z,1668019520.381 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:20.544Z,1668019520.544 [MultiRay](INFO): White lights on
2022-11-09T18:45:20.633Z,1668019520.633 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:20.885Z,1668019520.885 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:21.137Z,1668019521.137 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:21.389Z,1668019521.389 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:21.641Z,1668019521.641 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:21.893Z,1668019521.893 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:22.145Z,1668019522.145 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:22.397Z,1668019522.397 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:22.649Z,1668019522.649 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:22.901Z,1668019522.901 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:23.153Z,1668019523.153 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:23.405Z,1668019523.405 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:23.657Z,1668019523.657 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:23.909Z,1668019523.909 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:24.161Z,1668019524.161 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:24.413Z,1668019524.413 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:24.665Z,1668019524.665 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:24.919Z,1668019524.919 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:25.174Z,1668019525.174 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:25.425Z,1668019525.425 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:25.677Z,1668019525.677 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:25.726Z,1668019525.726 [multiray_test:G.Wait](INFO): Done Waiting.
2022-11-09T18:45:25.727Z,1668019525.727 [multiray_test:G.Wait] Stopped
2022-11-09T18:45:25.727Z,1668019525.727 [multiray_test:G.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:25.727Z,1668019525.727 [multiray_test:H] Running Loop=1
2022-11-09T18:45:25.929Z,1668019525.929 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:26.137Z,1668019526.137 [multiray_test:H] Stopped
2022-11-09T18:45:26.137Z,1668019526.137 [multiray_test:I.Wait] Running Loop=1
2022-11-09T18:45:26.137Z,1668019526.137 [multiray_test:I.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:26.181Z,1668019526.181 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:26.433Z,1668019526.433 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:26.689Z,1668019526.689 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:26.704Z,1668019526.704 [MultiRay](IMPORTANT): All lights off
2022-11-09T18:45:26.937Z,1668019526.937 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:27.189Z,1668019527.189 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:27.441Z,1668019527.441 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:27.693Z,1668019527.693 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:27.945Z,1668019527.945 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:28.197Z,1668019528.197 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:28.449Z,1668019528.449 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:28.701Z,1668019528.701 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:28.955Z,1668019528.955 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:29.209Z,1668019529.209 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:29.461Z,1668019529.461 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:29.713Z,1668019529.713 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:29.965Z,1668019529.965 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:30.217Z,1668019530.217 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:30.469Z,1668019530.469 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:30.721Z,1668019530.721 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:30.973Z,1668019530.973 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:31.225Z,1668019531.225 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:31.477Z,1668019531.477 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:31.729Z,1668019531.729 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:31.799Z,1668019531.799 [multiray_test:I.Wait](INFO): Done Waiting.
2022-11-09T18:45:31.799Z,1668019531.799 [multiray_test:I.Wait] Stopped
2022-11-09T18:45:31.799Z,1668019531.799 [multiray_test:I.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:31.799Z,1668019531.799 [multiray_test:J] Running Loop=1
2022-11-09T18:45:31.981Z,1668019531.981 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:32.209Z,1668019532.209 [multiray_test:J] Stopped
2022-11-09T18:45:32.210Z,1668019532.210 [multiray_test:K.Wait] Running Loop=1
2022-11-09T18:45:32.210Z,1668019532.210 [multiray_test:K.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:32.233Z,1668019532.233 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:32.485Z,1668019532.485 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:32.737Z,1668019532.737 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:32.989Z,1668019532.989 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:33.241Z,1668019533.241 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:33.485Z,1668019533.485 [MultiRay](INFO): Red lights on
2022-11-09T18:45:33.493Z,1668019533.493 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:33.745Z,1668019533.745 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:33.997Z,1668019533.997 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:34.249Z,1668019534.249 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:34.501Z,1668019534.501 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:34.753Z,1668019534.753 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:35.009Z,1668019535.009 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:35.261Z,1668019535.261 [DAT](DEBUG): checking for online mode acknowledgment
2022-11-09T18:45:35.261Z,1668019535.261 [DAT](FAULT): failed to enter online mode
2022-11-09T18:45:35.261Z,1668019535.261 [DAT](FAULT): Failure returning to online mode
2022-11-09T18:45:35.261Z,1668019535.261 [DAT] Communications Fault, FailCount= 1
2022-11-09T18:45:35.261Z,1668019535.261 [DAT](ERROR): Communications Fault
2022-11-09T18:45:35.455Z,1668019535.455 [CBIT](ERROR): Communications Fault in component: DAT
2022-11-09T18:45:35.665Z,1668019535.665 [DAT](INFO): Powering down
2022-11-09T18:45:36.650Z,1668019536.650 [CBIT](INFO): Clearing failed state for component DAT
2022-11-09T18:45:36.650Z,1668019536.650 [DAT] No Fault, FailCount= 1
2022-11-09T18:45:37.846Z,1668019537.846 [multiray_test:K.Wait](INFO): Done Waiting.
2022-11-09T18:45:37.846Z,1668019537.846 [multiray_test:K.Wait] Stopped
2022-11-09T18:45:37.847Z,1668019537.847 [multiray_test:K.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:37.847Z,1668019537.847 [multiray_test:L] Running Loop=1
2022-11-09T18:45:38.262Z,1668019538.262 [multiray_test:L] Stopped
2022-11-09T18:45:38.263Z,1668019538.263 [multiray_test:M.Wait] Running Loop=1
2022-11-09T18:45:38.263Z,1668019538.263 [multiray_test:M.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:38.726Z,1668019538.726 [DAT](INFO): Powering up
2022-11-09T18:45:38.727Z,1668019538.727 [DAT](DEBUG): Initializing DAT.
2022-11-09T18:45:38.742Z,1668019538.742 [MultiRay](INFO): White lights on
2022-11-09T18:45:43.914Z,1668019543.914 [multiray_test:M.Wait](INFO): Done Waiting.
2022-11-09T18:45:43.914Z,1668019543.914 [multiray_test:M.Wait] Stopped
2022-11-09T18:45:43.914Z,1668019543.914 [multiray_test:M.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:43.914Z,1668019543.914 [multiray_test:N] Running Loop=1
2022-11-09T18:45:44.333Z,1668019544.333 [multiray_test:N] Stopped
2022-11-09T18:45:44.333Z,1668019544.333 [multiray_test:O.Wait] Running Loop=1
2022-11-09T18:45:44.333Z,1668019544.333 [multiray_test:O.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:44.878Z,1668019544.878 [MultiRay](IMPORTANT): All lights off
2022-11-09T18:45:50.002Z,1668019550.002 [multiray_test:O.Wait](INFO): Done Waiting.
2022-11-09T18:45:50.002Z,1668019550.002 [multiray_test:O.Wait] Stopped
2022-11-09T18:45:50.002Z,1668019550.002 [multiray_test:O.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:50.002Z,1668019550.002 [multiray_test:P] Running Loop=1
2022-11-09T18:45:50.384Z,1668019550.384 [multiray_test:P] Stopped
2022-11-09T18:45:50.384Z,1668019550.384 [multiray_test:Q.Wait] Running Loop=1
2022-11-09T18:45:50.385Z,1668019550.385 [multiray_test:Q.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:51.665Z,1668019551.665 [MultiRay](INFO): Red lights on
2022-11-09T18:45:53.891Z,1668019553.891 [DAT](INFO): commRate: 800
2022-11-09T18:45:55.960Z,1668019555.960 [DAT](INFO): entering command mode
2022-11-09T18:45:56.062Z,1668019556.062 [multiray_test:Q.Wait](INFO): Done Waiting.
2022-11-09T18:45:56.063Z,1668019556.063 [multiray_test:Q.Wait] Stopped
2022-11-09T18:45:56.063Z,1668019556.063 [multiray_test:Q.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:45:56.063Z,1668019556.063 [multiray_test:U] Running Loop=1
2022-11-09T18:45:56.161Z,1668019556.161 [DAT](INFO): setting verbose to 3
2022-11-09T18:45:56.418Z,1668019556.418 [DAT](INFO): set verbose to 3
2022-11-09T18:45:56.418Z,1668019556.418 [DAT](INFO): setting DatVerbose to 27440
2022-11-09T18:45:56.484Z,1668019556.484 [multiray_test:U] Stopped
2022-11-09T18:45:56.484Z,1668019556.484 [multiray_test:R.Wait] Running Loop=1
2022-11-09T18:45:56.484Z,1668019556.484 [multiray_test:R.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:45:56.670Z,1668019556.670 [DAT](INFO): set DatVerbose to 27440
2022-11-09T18:45:56.670Z,1668019556.670 [DAT](INFO): setting transmit power to 8
2022-11-09T18:45:56.876Z,1668019556.876 [MultiRay](INFO): White lights on
2022-11-09T18:45:56.922Z,1668019556.922 [DAT](INFO): set transmit power to 8
2022-11-09T18:45:56.922Z,1668019556.922 [DAT](INFO): setting local address to 10
2022-11-09T18:45:57.174Z,1668019557.174 [DAT](INFO): set local address to 10
2022-11-09T18:45:57.175Z,1668019557.175 [DAT](INFO): Setting time to: 18:45:57 And date to:11/9/2022
2022-11-09T18:45:57.426Z,1668019557.426 [DAT](INFO): Local DAT time set to Wed Nov 9, 2022  18:45:57  

2022-11-09T18:45:57.426Z,1668019557.426 [DAT](INFO): setting remote address to 1
2022-11-09T18:45:57.678Z,1668019557.678 [DAT](INFO): set remote address to 1
2022-11-09T18:45:57.678Z,1668019557.678 [DAT](INFO): entering online mode
2022-11-09T18:45:57.930Z,1668019557.930 [DAT](INFO): commRate: 800
2022-11-09T18:45:57.931Z,1668019557.931 [DAT](INFO): online mode acknowledged
2022-11-09T18:45:57.931Z,1668019557.931 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2022-11-09T18:46:01.206Z,1668019561.206 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2022-11-09T18:46:02.097Z,1668019562.097 [multiray_test:R.Wait](INFO): Done Waiting.
2022-11-09T18:46:02.097Z,1668019562.097 [multiray_test:R.Wait] Stopped
2022-11-09T18:46:02.097Z,1668019562.097 [multiray_test:R.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:46:02.097Z,1668019562.097 [multiray_test:S] Running Loop=1
2022-11-09T18:46:02.514Z,1668019562.514 [multiray_test:S] Stopped
2022-11-09T18:46:02.514Z,1668019562.514 [multiray_test:T.Wait] Running Loop=1
2022-11-09T18:46:02.514Z,1668019562.514 [multiray_test:T.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:46:02.989Z,1668019562.989 [MultiRay](IMPORTANT): All lights off
2022-11-09T18:46:03.001Z,1668019563.001 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-11-09T18:46:08.205Z,1668019568.205 [multiray_test:T.Wait](INFO): Done Waiting.
2022-11-09T18:46:08.205Z,1668019568.205 [multiray_test:T.Wait] Stopped
2022-11-09T18:46:08.205Z,1668019568.205 [multiray_test:T.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:46:08.205Z,1668019568.205 [multiray_test](INFO): Completed multiray_test
2022-11-09T18:46:08.205Z,1668019568.205 [MissionManager](INFO): multiray_test is completed.
2022-11-09T18:46:08.205Z,1668019568.205 [MissionManager](INFO): Uninitializing Mission multiray_test
2022-11-09T18:46:08.205Z,1668019568.205 [multiray_test] Stopped
2022-11-09T18:46:08.206Z,1668019568.206 [multiray_test](DEBUG): Aggregate::uninitialize multiray_test
2022-11-09T18:46:08.206Z,1668019568.206 [multiray_test:A] Stopped
2022-11-09T18:46:08.594Z,1668019568.594 [MissionManager](IMPORTANT): Started mission Default
2022-11-09T18:46:08.595Z,1668019568.595 [Default] Running Loop=1
2022-11-09T18:46:08.595Z,1668019568.595 [Default](DEBUG): Aggregate::initialize Default
2022-11-09T18:46:08.595Z,1668019568.595 [Default:B.GoToSurface] Running Loop=1
2022-11-09T18:46:08.595Z,1668019568.595 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-11-09T18:46:08.595Z,1668019568.595 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-11-09T18:46:08.595Z,1668019568.595 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-11-09T18:46:08.596Z,1668019568.596 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-11-09T18:46:08.596Z,1668019568.596 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-11-09T18:46:08.597Z,1668019568.597 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-11-09T18:46:08.597Z,1668019568.597 [Default:A.Wait] Running Loop=1
2022-11-09T18:46:08.597Z,1668019568.597 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-11-09T18:46:11.329Z,1668019571.329 [CommandExec](IMPORTANT): got command quit
2022-11-09T18:46:12.332Z,1668019572.332 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-11-09T18:46:12.333Z,1668019572.333 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:12.333Z,1668019572.333 [CommandExec](INFO): Uninitializing the command executive.
2022-11-09T18:46:12.333Z,1668019572.333 [CommandExec](INFO): Uninitializing the command scheduler.
2022-11-09T18:46:12.333Z,1668019572.333 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.344Z,1668019572.344 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-11-09T18:46:12.344Z,1668019572.344 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-11-09T18:46:12.344Z,1668019572.344 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.345Z,1668019572.345 [NavChartDb](INFO): Join timeout helper Thread ID is 5861
2022-11-09T18:46:12.436Z,1668019572.436 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:12.437Z,1668019572.437 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.444Z,1668019572.444 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-11-09T18:46:12.444Z,1668019572.444 [DAT ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.445Z,1668019572.445 [DAT](INFO): Join timeout helper Thread ID is 5862
2022-11-09T18:46:12.569Z,1668019572.569 [DAT](INFO): Powering down
2022-11-09T18:46:12.641Z,1668019572.641 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:12.641Z,1668019572.641 [DAT](INFO): Powering down
2022-11-09T18:46:12.642Z,1668019572.642 [DAT ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.656Z,1668019572.656 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-11-09T18:46:12.656Z,1668019572.656 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.657Z,1668019572.657 [Radio_Surface](INFO): Join timeout helper Thread ID is 5863
2022-11-09T18:46:12.720Z,1668019572.720 [Radio_Surface](INFO): Powering down
2022-11-09T18:46:12.721Z,1668019572.721 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:12.721Z,1668019572.721 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.728Z,1668019572.728 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-11-09T18:46:12.728Z,1668019572.728 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:12.729Z,1668019572.729 [Onboard](INFO): Join timeout helper Thread ID is 5864
2022-11-09T18:46:12.760Z,1668019572.760 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-11-09T18:46:15.204Z,1668019575.204 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:15.205Z,1668019575.205 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.220Z,1668019575.220 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-11-09T18:46:15.220Z,1668019575.220 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.221Z,1668019575.221 [DataOverHttps](INFO): Join timeout helper Thread ID is 5865
2022-11-09T18:46:15.772Z,1668019575.772 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:15.773Z,1668019575.773 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.785Z,1668019575.785 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-11-09T18:46:15.785Z,1668019575.785 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.786Z,1668019575.786 [BackseatComponent](INFO): Join timeout helper Thread ID is 5866
2022-11-09T18:46:15.976Z,1668019575.976 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:15.977Z,1668019575.977 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.989Z,1668019575.989 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-11-09T18:46:15.989Z,1668019575.989 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.990Z,1668019575.990 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5867
2022-11-09T18:46:15.990Z,1668019575.990 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:15.991Z,1668019575.991 [WetLabsBB2FL](INFO): Powering down
2022-11-09T18:46:15.991Z,1668019575.991 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.993Z,1668019575.993 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-11-09T18:46:15.993Z,1668019575.993 [logger ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:15.993Z,1668019575.993 [logger](INFO): Join timeout helper Thread ID is 5868
2022-11-09T18:46:16.017Z,1668019576.017 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:16.017Z,1668019576.017 [logger ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.033Z,1668019576.033 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-11-09T18:46:16.033Z,1668019576.033 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.033Z,1668019576.033 [CommandLine](INFO): Join timeout helper Thread ID is 5869
2022-11-09T18:46:16.129Z,1668019576.129 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:16.129Z,1668019576.129 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.133Z,1668019576.133 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-11-09T18:46:16.133Z,1668019576.133 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.134Z,1668019576.134 [CommandExec](INFO): Join timeout helper Thread ID is 5870
2022-11-09T18:46:16.135Z,1668019576.135 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-11-09T18:46:16.135Z,1668019576.135 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.135Z,1668019576.135 [controlThread](INFO): Join timeout helper Thread ID is 5871
2022-11-09T18:46:16.220Z,1668019576.220 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-11-09T18:46:16.221Z,1668019576.221 [controlThread](DEBUG): Uninitializing ControlThread
2022-11-09T18:46:16.221Z,1668019576.221 [AHRS_M2](INFO): Powering down
2022-11-09T18:46:16.294Z,1668019576.294 [MultiRay](INFO): Powering down.
2022-11-09T18:46:16.295Z,1668019576.295 [NAL9602](INFO): Powering down
2022-11-09T18:46:16.296Z,1668019576.296 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-11-09T18:46:16.297Z,1668019576.297 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-11-09T18:46:16.298Z,1668019576.298 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-11-09T18:46:16.298Z,1668019576.298 [MissionManager](INFO): Uninitializing Mission Default
2022-11-09T18:46:16.298Z,1668019576.298 [Default] Stopped
2022-11-09T18:46:16.299Z,1668019576.299 [Default](DEBUG): Aggregate::uninitialize Default
2022-11-09T18:46:16.299Z,1668019576.299 [Default:A.Wait] Stopped
2022-11-09T18:46:16.299Z,1668019576.299 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-11-09T18:46:16.299Z,1668019576.299 [Default:B.GoToSurface] Stopped
2022-11-09T18:46:16.299Z,1668019576.299 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-11-09T18:46:16.302Z,1668019576.302 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-11-09T18:46:16.302Z,1668019576.302 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-11-09T18:46:16.302Z,1668019576.302 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-11-09T18:46:16.303Z,1668019576.303 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-11-09T18:46:16.303Z,1668019576.303 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-11-09T18:46:16.303Z,1668019576.303 [BuoyancyServo](INFO): Powering down
2022-11-09T18:46:16.316Z,1668019576.316 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-11-09T18:46:16.316Z,1668019576.316 [ElevatorServo](INFO): Powering down
2022-11-09T18:46:16.317Z,1668019576.317 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-11-09T18:46:16.317Z,1668019576.317 [MassServo](INFO): Powering down
2022-11-09T18:46:16.318Z,1668019576.318 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-11-09T18:46:16.318Z,1668019576.318 [RudderServo](INFO): Powering down
2022-11-09T18:46:16.319Z,1668019576.319 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-11-09T18:46:16.319Z,1668019576.319 [ThrusterHE](INFO): Powering down
2022-11-09T18:46:16.320Z,1668019576.320 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-11-09T18:46:16.321Z,1668019576.321 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-11-09T18:46:16.321Z,1668019576.321 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-11-09T18:46:16.321Z,1668019576.321 [CBIT](DEBUG): Powering off loads.
2022-11-09T18:46:16.332Z,1668019576.332 [CBIT](DEBUG): Disabling WDT.
2022-11-09T18:46:16.344Z,1668019576.344 [CBIT](DEBUG): Opening all GF detection circuits.
2022-11-09T18:46:16.345Z,1668019576.345 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.375Z,1668019576.375 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.421Z,1668019576.421 [DAT ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.431Z,1668019576.431 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.435Z,1668019576.435 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.442Z,1668019576.442 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.486Z,1668019576.486 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.527Z,1668019576.527 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-11-09T18:46:16.579Z,1668019576.579 [logger ThreadHandler](INFO): Thread cancelled.