2019-10-30T22:32:54.842Z,1572474774.842 [Supervisor](DEBUG): Initializing supervisor.
2019-10-30T22:32:54.844Z,1572474774.844 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-30T22:32:54.845Z,1572474774.845 [SyncHandler](INFO): Protected caller Thread ID is 2821
2019-10-30T22:32:54.845Z,1572474774.845 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-30T22:32:54.846Z,1572474774.846 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-30T22:32:54.847Z,1572474774.847 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2822
2019-10-30T22:32:54.849Z,1572474774.849 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-30T22:32:54.860Z,1572474774.860 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-30T22:32:54.861Z,1572474774.861 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-30T22:32:54.861Z,1572474774.861 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2823
2019-10-30T22:32:54.862Z,1572474774.862 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-30T22:32:54.863Z,1572474774.863 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-30T22:32:54.864Z,1572474774.864 [logger ThreadHandler](INFO): Protected caller Thread ID is 2824
2019-10-30T22:32:54.865Z,1572474774.865 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-30T22:32:54.866Z,1572474774.866 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-30T22:32:54.867Z,1572474774.867 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-30T22:32:55.330Z,1572474775.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-30T22:32:55.331Z,1572474775.331 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-30T22:32:55.428Z,1572474775.428 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-30T22:32:55.429Z,1572474775.429 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-30T22:32:55.728Z,1572474775.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-30T22:32:55.728Z,1572474775.728 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-30T22:32:55.864Z,1572474775.864 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-30T22:32:55.865Z,1572474775.865 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-30T22:32:56.050Z,1572474776.050 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-30T22:32:56.050Z,1572474776.050 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-30T22:32:56.524Z,1572474776.524 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-30T22:32:56.525Z,1572474776.525 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-30T22:32:57.026Z,1572474777.026 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-30T22:32:57.026Z,1572474777.026 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-30T22:32:57.167Z,1572474777.167 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-30T22:32:57.167Z,1572474777.167 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-30T22:32:57.352Z,1572474777.352 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-30T22:32:57.353Z,1572474777.353 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-30T22:32:57.448Z,1572474777.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-30T22:32:57.448Z,1572474777.448 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-30T22:32:57.733Z,1572474777.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-30T22:32:57.734Z,1572474777.734 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-30T22:32:57.815Z,1572474777.815 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-30T22:32:57.917Z,1572474777.917 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-30T22:32:57.917Z,1572474777.917 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-30T22:32:58.501Z,1572474778.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-30T22:32:58.502Z,1572474778.502 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-30T22:32:58.873Z,1572474778.873 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-30T22:32:58.875Z,1572474778.875 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-10-30T22:32:58.876Z,1572474778.876 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-10-30T22:32:59.072Z,1572474779.072 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-10-30T22:32:59.170Z,1572474779.170 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-10-30T22:32:59.267Z,1572474779.267 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-10-30T22:32:59.487Z,1572474779.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-30T22:32:59.487Z,1572474779.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-10-30T22:32:59.572Z,1572474779.572 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-10-30T22:32:59.666Z,1572474779.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-10-30T22:32:59.763Z,1572474779.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-10-30T22:32:59.847Z,1572474779.847 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-10-30T22:32:59.954Z,1572474779.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-10-30T22:33:00.133Z,1572474780.133 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-10-30T22:33:00.262Z,1572474780.262 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-10-30T22:33:00.268Z,1572474780.268 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-30T22:33:00.588Z,1572474780.588 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-30T22:33:00.593Z,1572474780.593 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-30T22:33:00.595Z,1572474780.595 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-30T22:33:00.600Z,1572474780.600 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-30T22:33:00.600Z,1572474780.600 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-30T22:33:00.605Z,1572474780.605 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-30T22:33:00.606Z,1572474780.606 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-30T22:33:00.611Z,1572474780.611 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-30T22:33:00.679Z,1572474780.679 [AHRS_M2] Loaded
2019-10-30T22:33:00.680Z,1572474780.680 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-30T22:33:00.755Z,1572474780.755 [DataOverHttps] Loaded
2019-10-30T22:33:00.755Z,1572474780.755 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-30T22:33:00.756Z,1572474780.756 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075C4E0
2019-10-30T22:33:00.757Z,1572474780.757 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2903
2019-10-30T22:33:00.769Z,1572474780.769 [Depth_Keller] Loaded
2019-10-30T22:33:00.770Z,1572474780.770 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-30T22:33:00.774Z,1572474780.774 [DropWeight] Loaded
2019-10-30T22:33:00.775Z,1572474780.775 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-30T22:33:00.830Z,1572474780.830 [DUSBL_Hydroid] Loaded
2019-10-30T22:33:00.830Z,1572474780.830 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-10-30T22:33:00.876Z,1572474780.876 [Micromodem] Loaded
2019-10-30T22:33:00.876Z,1572474780.876 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-10-30T22:33:00.970Z,1572474780.970 [NAL9602] Loaded
2019-10-30T22:33:00.970Z,1572474780.970 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-30T22:33:00.985Z,1572474780.985 [Onboard] Loaded
2019-10-30T22:33:00.985Z,1572474780.985 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-30T22:33:00.991Z,1572474780.991 [PowerOnly] Loaded
2019-10-30T22:33:00.991Z,1572474780.991 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-10-30T22:33:00.998Z,1572474780.998 [Radio_Surface] Loaded
2019-10-30T22:33:00.998Z,1572474780.998 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-30T22:33:00.999Z,1572474780.999 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078C4E0
2019-10-30T22:33:00.999Z,1572474780.999 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2904
2019-10-30T22:33:01.042Z,1572474781.042 [RDI_Pathfinder] Loaded
2019-10-30T22:33:01.042Z,1572474781.042 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-10-30T22:33:02.843Z,1572474782.843 [BPC1] Loaded
2019-10-30T22:33:02.843Z,1572474782.843 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-30T22:33:02.844Z,1572474782.844 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-30T22:33:02.844Z,1572474782.844 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-30T22:33:02.860Z,1572474782.860 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-30T22:33:02.861Z,1572474782.861 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-30T22:33:02.963Z,1572474782.963 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-30T22:33:02.963Z,1572474782.963 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-30T22:33:02.982Z,1572474782.982 [NavChart] Loaded
2019-10-30T22:33:02.983Z,1572474782.983 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-30T22:33:02.986Z,1572474782.986 [UniversalFixResidualReporter] Loaded
2019-10-30T22:33:02.987Z,1572474782.987 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-30T22:33:02.987Z,1572474782.987 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-30T22:33:02.988Z,1572474782.988 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-30T22:33:03.090Z,1572474783.090 [BuoyancyServo] Loaded
2019-10-30T22:33:03.090Z,1572474783.090 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-30T22:33:03.105Z,1572474783.105 [ElevatorServo] Loaded
2019-10-30T22:33:03.105Z,1572474783.105 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-30T22:33:03.119Z,1572474783.119 [MassServo] Loaded
2019-10-30T22:33:03.120Z,1572474783.120 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-30T22:33:03.134Z,1572474783.134 [RudderServo] Loaded
2019-10-30T22:33:03.135Z,1572474783.135 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-30T22:33:03.148Z,1572474783.148 [ThrusterServo] Loaded
2019-10-30T22:33:03.149Z,1572474783.149 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-30T22:33:03.149Z,1572474783.149 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-30T22:33:03.150Z,1572474783.150 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-30T22:33:03.391Z,1572474783.391 [CTD_NeilBrown] Loaded
2019-10-30T22:33:03.391Z,1572474783.391 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-10-30T22:33:03.392Z,1572474783.392 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408D74E0
2019-10-30T22:33:03.392Z,1572474783.392 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2905
2019-10-30T22:33:03.406Z,1572474783.406 [PAR_Licor] Loaded
2019-10-30T22:33:03.407Z,1572474783.407 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-30T22:33:03.449Z,1572474783.449 [WetLabsSeaOWL_UV_A] Loaded
2019-10-30T22:33:03.449Z,1572474783.449 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-10-30T22:33:03.450Z,1572474783.450 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409074E0
2019-10-30T22:33:03.450Z,1572474783.450 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2906
2019-10-30T22:33:03.451Z,1572474783.451 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-30T22:33:03.451Z,1572474783.451 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-30T22:33:03.735Z,1572474783.735 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-30T22:33:03.735Z,1572474783.735 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-30T22:33:03.776Z,1572474783.776 [DepthRateCalculator] Loaded
2019-10-30T22:33:03.776Z,1572474783.776 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-30T22:33:03.781Z,1572474783.781 [PitchRateCalculator] Loaded
2019-10-30T22:33:03.782Z,1572474783.782 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-30T22:33:03.793Z,1572474783.793 [SpeedCalculator] Loaded
2019-10-30T22:33:03.794Z,1572474783.794 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-30T22:33:03.814Z,1572474783.814 [TempGradientCalculator] Loaded
2019-10-30T22:33:03.814Z,1572474783.814 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-30T22:33:03.820Z,1572474783.820 [YawRateCalculator] Loaded
2019-10-30T22:33:03.820Z,1572474783.820 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-30T22:33:03.858Z,1572474783.858 [ElevatorOffsetCalculator] Loaded
2019-10-30T22:33:03.859Z,1572474783.859 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-30T22:33:03.859Z,1572474783.859 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-30T22:33:03.860Z,1572474783.860 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-30T22:33:03.989Z,1572474783.989 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-30T22:33:04.010Z,1572474784.010 [SBIT] Loaded
2019-10-30T22:33:04.010Z,1572474784.010 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-30T22:33:04.011Z,1572474784.011 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-30T22:33:04.022Z,1572474784.022 [IBIT] Loaded
2019-10-30T22:33:04.022Z,1572474784.022 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-30T22:33:04.025Z,1572474784.025 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-30T22:33:04.158Z,1572474784.158 [CBIT] Loaded
2019-10-30T22:33:04.158Z,1572474784.158 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-30T22:33:04.158Z,1572474784.158 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-30T22:33:04.159Z,1572474784.159 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-30T22:33:04.236Z,1572474784.236 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-30T22:33:04.236Z,1572474784.236 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-30T22:33:04.332Z,1572474784.332 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-30T22:33:04.332Z,1572474784.332 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-30T22:33:04.397Z,1572474784.397 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-30T22:33:04.478Z,1572474784.478 [VerticalControl] Loaded
2019-10-30T22:33:04.478Z,1572474784.478 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-30T22:33:04.479Z,1572474784.479 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-30T22:33:04.533Z,1572474784.533 [HorizontalControl] Loaded
2019-10-30T22:33:04.534Z,1572474784.534 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-30T22:33:04.534Z,1572474784.534 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-30T22:33:04.536Z,1572474784.536 [SpeedControl] Loaded
2019-10-30T22:33:04.536Z,1572474784.536 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-30T22:33:04.537Z,1572474784.537 [LoopControl](DEBUG): Construct LoopControl.
2019-10-30T22:33:04.537Z,1572474784.537 [LoopControl] Loaded
2019-10-30T22:33:04.538Z,1572474784.538 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-30T22:33:04.538Z,1572474784.538 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-30T22:33:04.539Z,1572474784.539 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-30T22:33:04.569Z,1572474784.569 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-30T22:33:04.573Z,1572474784.573 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-30T22:33:04.574Z,1572474784.574 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-30T22:33:04.580Z,1572474784.580 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-30T22:33:04.581Z,1572474784.581 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AE44E0
2019-10-30T22:33:04.582Z,1572474784.582 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2907
2019-10-30T22:33:04.586Z,1572474784.586 [Supervisor](INFO): Main Thread ID is 802
2019-10-30T22:33:04.586Z,1572474784.586 [Supervisor](DEBUG): Running supervisor.
2019-10-30T22:33:04.587Z,1572474784.587 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2908
2019-10-30T22:33:04.589Z,1572474784.589 [controlThread ThreadHandler](INFO): Handler Thread ID is 2909
2019-10-30T22:33:04.590Z,1572474784.590 [controlThread](DEBUG): Initializing ControlThread
2019-10-30T22:33:04.596Z,1572474784.596 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-30T22:33:04.596Z,1572474784.596 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-30T22:33:04.601Z,1572474784.601 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-30T22:33:04.601Z,1572474784.601 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-30T22:33:04.602Z,1572474784.602 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-30T22:33:04.602Z,1572474784.602 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-30T22:33:04.603Z,1572474784.603 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-30T22:33:04.603Z,1572474784.603 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-30T22:33:04.603Z,1572474784.603 [SBIT](INFO): Initialize SBIT Component.
2019-10-30T22:33:04.604Z,1572474784.604 [SBIT](IMPORTANT): git: 2019-10-15
2019-10-30T22:33:04.604Z,1572474784.604 [SBIT](INFO): git hash: 5afd4984613942c073d284d94e598e25fc5569fb
2019-10-30T22:33:04.604Z,1572474784.604 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-30T22:33:04.606Z,1572474784.606 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2019-10-30T22:33:04.607Z,1572474784.607 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-10-30T22:33:04.607Z,1572474784.607 [IBIT](INFO): Initialize IBIT Component.
2019-10-30T22:33:04.608Z,1572474784.608 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-30T22:33:04.609Z,1572474784.609 [logger ThreadHandler](INFO): Handler Thread ID is 2910
2019-10-30T22:33:04.621Z,1572474784.621 [CBIT](DEBUG): Initialized mux pins.
2019-10-30T22:33:04.621Z,1572474784.621 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-30T22:33:04.629Z,1572474784.629 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2911
2019-10-30T22:33:04.630Z,1572474784.630 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-30T22:33:04.641Z,1572474784.641 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2912
2019-10-30T22:33:04.645Z,1572474784.645 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-30T22:33:04.645Z,1572474784.645 [CBIT](DEBUG): Initializing heartbeat.
2019-10-30T22:33:04.653Z,1572474784.653 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2913
2019-10-30T22:33:04.654Z,1572474784.654 [CTD_NeilBrown](INFO): Powering down
2019-10-30T22:33:04.673Z,1572474784.673 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2914
2019-10-30T22:33:04.674Z,1572474784.674 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-10-30T22:33:04.705Z,1572474784.705 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2915
2019-10-30T22:33:04.711Z,1572474784.711 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-30T22:33:04.712Z,1572474784.712 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-30T22:33:04.712Z,1572474784.712 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-30T22:33:04.712Z,1572474784.712 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-30T22:33:04.712Z,1572474784.712 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-30T22:33:04.712Z,1572474784.712 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-30T22:33:04.713Z,1572474784.713 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-30T22:33:04.713Z,1572474784.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-30T22:33:04.713Z,1572474784.713 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-30T22:33:04.713Z,1572474784.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-30T22:33:04.714Z,1572474784.714 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-30T22:33:04.714Z,1572474784.714 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-30T22:33:04.714Z,1572474784.714 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-30T22:33:04.714Z,1572474784.714 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-30T22:33:04.714Z,1572474784.714 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-30T22:33:04.715Z,1572474784.715 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-30T22:33:04.717Z,1572474784.717 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-30T22:33:04.717Z,1572474784.717 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-30T22:33:04.753Z,1572474784.753 [CBIT](DEBUG): Backplane powered.
2019-10-30T22:33:04.753Z,1572474784.753 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-30T22:33:04.755Z,1572474784.755 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-30T22:33:04.756Z,1572474784.756 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-30T22:33:04.756Z,1572474784.756 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-30T22:33:04.757Z,1572474784.757 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-30T22:33:04.785Z,1572474784.785 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-30T22:33:04.808Z,1572474784.808 [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>


2019-10-30T22:33:04.833Z,1572474784.833 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-30T22:33:04.909Z,1572474784.909 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-30T22:33:04.934Z,1572474784.934 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-30T22:33:04.935Z,1572474784.935 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-30T22:33:04.958Z,1572474784.958 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-30T22:33:04.960Z,1572474784.960 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-30T22:33:04.990Z,1572474784.990 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-30T22:33:05.006Z,1572474785.006 [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="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

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

        <Assign><Sequence/><Arg Name="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>


2019-10-30T22:33:05.024Z,1572474785.024 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-10-30T22:33:05.037Z,1572474785.037 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-30T22:33:05.045Z,1572474785.045 [Radio_Surface](INFO): Powering up
2019-10-30T22:33:05.096Z,1572474785.096 [DUSBL_Hydroid](INFO): Powering up
2019-10-30T22:33:05.096Z,1572474785.096 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-10-30T22:33:05.291Z,1572474785.291 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-30T22:33:05.301Z,1572474785.301 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-30T22:33:05.302Z,1572474785.302 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-30T22:33:05.309Z,1572474785.309 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-30T22:33:05.310Z,1572474785.310 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-30T22:33:05.317Z,1572474785.317 [MassServo](DEBUG): Initializing MassServo.
2019-10-30T22:33:05.318Z,1572474785.318 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-30T22:33:05.325Z,1572474785.325 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-30T22:33:05.326Z,1572474785.326 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-30T22:33:05.333Z,1572474785.333 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-30T22:33:05.452Z,1572474785.452 [Micromodem](INFO): Powering up
2019-10-30T22:33:05.452Z,1572474785.452 [Micromodem](DEBUG): Initializing Micromodem.
2019-10-30T22:33:06.213Z,1572474786.213 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-10-30T22:33:06.213Z,1572474786.213 [RudderServo](FAULT): Rudder failed to initialize
2019-10-30T22:33:06.213Z,1572474786.213 [RudderServo] Communications Fault, FailCount= 1
2019-10-30T22:33:06.213Z,1572474786.213 [RudderServo](ERROR): Communications Fault
2019-10-30T22:33:06.324Z,1572474786.324 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-10-30T22:33:06.522Z,1572474786.522 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-30T22:33:06.522Z,1572474786.522 [RudderServo](INFO): Powering down
2019-10-30T22:33:07.199Z,1572474787.199 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-30T22:33:07.318Z,1572474787.318 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-30T22:33:07.322Z,1572474787.322 [CBIT](INFO): Clearing failed state for component RudderServo
2019-10-30T22:33:07.322Z,1572474787.322 [RudderServo] No Fault, FailCount= 1
2019-10-30T22:33:10.411Z,1572474790.411 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-10-30T22:33:13.336Z,1572474793.336 [Micromodem](INFO): Nmea in: $CATMG,2019-10-30T22:33:12.379671Z,RTC,RTC*56

2019-10-30T22:33:13.336Z,1572474793.336 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-10-30T22:33:12.379671Z,RTC,RTC*56

2019-10-30T22:33:18.589Z,1572474798.589 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-10-30T22:33:21.799Z,1572474801.799 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-10-30T22:33:22.608Z,1572474802.608 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-10-30T22:33:22.609Z,1572474802.609 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-10-30T22:33:23.010Z,1572474803.010 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-10-30T22:33:23.022Z,1572474803.022 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-10-30T22:33:23.022Z,1572474803.022 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-10-30T22:33:23.415Z,1572474803.415 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-10-30T22:33:23.415Z,1572474803.415 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2019-10-30T22:33:23.815Z,1572474803.815 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2019-10-30T22:33:23.815Z,1572474803.815 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2019-10-30T22:33:24.223Z,1572474804.223 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2019-10-30T22:33:24.223Z,1572474804.223 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2019-10-30T22:33:24.627Z,1572474804.627 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2019-10-30T22:33:24.627Z,1572474804.627 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2019-10-30T22:33:25.031Z,1572474805.031 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2019-10-30T22:33:25.031Z,1572474805.031 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2019-10-30T22:33:25.438Z,1572474805.438 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2019-10-30T22:33:25.440Z,1572474805.440 [Micromodem](INFO): Nmea out: $CCCLK,2019,10,30,22,33,26*48

2019-10-30T22:33:25.839Z,1572474805.839 [Micromodem](INFO): Nmea in: $CACLK,2019,10,30,22,33,26*4A

2019-10-30T22:33:26.243Z,1572474806.243 [Micromodem](INFO): Nmea in: $CATMS,0,2019-10-30T22:33:27Z*7B

2019-10-30T22:33:26.244Z,1572474806.244 [Micromodem](INFO): Nmea in: $CATMG,2019-10-30T22:33:27.026231Z,USER_CMD,RTC*18

2019-10-30T22:33:26.736Z,1572474806.736 [RDI_Pathfinder](ERROR): Failed to parse:
:B  +0.00,        +0.00,        +0.00,   0.00,  7.00
2019-10-30T22:33:31.091Z,1572474811.091 [NAL9602](INFO): Powering up NAL9602
2019-10-30T22:33:33.161Z,1572474813.161 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-30T22:33:33.169Z,1572474813.169 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-30T22:33:42.232Z,1572474822.232 [NAL9602](INFO): NAL9602 initialized
2019-10-30T22:33:43.053Z,1572474823.053 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:33:44.001Z,1572474824.001 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.027319
CHAN A1 (24V): -0.028373
CHAN A2 (12V): -0.007045
CHAN A3 (5V): -0.001783
CHAN B0 (3.3V): 0.000199
CHAN B1 (3.15aV): 0.000426
CHAN B2 (3.15bV): 0.000305
CHAN B3 (GND): 0.002215
OPEN: 0.004865
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-30T22:34:26.687Z,1572474866.687 [SBIT](IMPORTANT): SBIT PASSED
2019-10-30T22:34:26.707Z,1572474866.707 [CommandLine](IMPORTANT): got command configSet list
2019-10-30T22:34:26.708Z,1572474866.708 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-30T22:34:26.708Z,1572474866.708 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=25 count;

2019-10-30T22:34:26.709Z,1572474866.709 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout=40 millisecond;

2019-10-30T22:34:26.709Z,1572474866.709 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity=3 enum;

2019-10-30T22:34:27.071Z,1572474867.071 [MissionManager](IMPORTANT): Started mission Startup
2019-10-30T22:34:27.071Z,1572474867.071 [Startup] Running Loop=1
2019-10-30T22:34:27.071Z,1572474867.071 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-30T22:34:27.071Z,1572474867.071 [Startup:A.GoToSurface] Running Loop=1
2019-10-30T22:34:27.071Z,1572474867.071 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:34:27.072Z,1572474867.072 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:34:27.072Z,1572474867.072 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:34:27.073Z,1572474867.073 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:34:27.073Z,1572474867.073 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:34:27.074Z,1572474867.074 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:34:27.075Z,1572474867.075 [Startup:StartupSatComms] Running Loop=1
2019-10-30T22:34:27.075Z,1572474867.075 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-30T22:34:27.075Z,1572474867.075 [Startup:StartupSatComms:A] Running Loop=1
2019-10-30T22:34:27.447Z,1572474867.447 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-30T22:35:27.233Z,1572474927.233 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-30T22:34:27.1Z
2019-10-30T22:35:27.233Z,1572474927.233 [Startup:StartupSatComms:A] Stopped
2019-10-30T22:35:27.233Z,1572474927.233 [Startup:StartupSatComms:B] Running Loop=1
2019-10-30T22:35:27.656Z,1572474927.656 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-30T22:36:04.795Z,1572474964.795 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-10-30T22:36:04.795Z,1572474964.795 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-30T22:36:04.805Z,1572474964.805 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-30T22:36:05.210Z,1572474965.210 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-30T22:36:05.210Z,1572474965.210 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-10-30T22:36:27.466Z,1572474987.466 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-30T22:35:27.2Z
2019-10-30T22:36:27.466Z,1572474987.466 [Startup:StartupSatComms:B] Stopped
2019-10-30T22:36:27.467Z,1572474987.467 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-30T22:36:27.467Z,1572474987.467 [Startup:StartupSatComms] Stopped
2019-10-30T22:36:27.467Z,1572474987.467 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-30T22:36:27.467Z,1572474987.467 [Startup](INFO): Completed Startup
2019-10-30T22:36:27.468Z,1572474987.468 [MissionManager](INFO): Startup is completed.
2019-10-30T22:36:27.468Z,1572474987.468 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-30T22:36:27.468Z,1572474987.468 [Startup] Stopped
2019-10-30T22:36:27.468Z,1572474987.468 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-30T22:36:27.468Z,1572474987.468 [Startup:A.GoToSurface] Stopped
2019-10-30T22:36:27.468Z,1572474987.468 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-30T22:36:27.893Z,1572474987.893 [MissionManager](IMPORTANT): Started mission Default
2019-10-30T22:36:27.893Z,1572474987.893 [Default] Running Loop=1
2019-10-30T22:36:27.893Z,1572474987.893 [Default](DEBUG): Aggregate::initialize Default
2019-10-30T22:36:27.893Z,1572474987.893 [Default:B.GoToSurface] Running Loop=1
2019-10-30T22:36:27.893Z,1572474987.893 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:36:27.894Z,1572474987.894 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:36:27.894Z,1572474987.894 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:36:27.894Z,1572474987.894 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:36:27.895Z,1572474987.895 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:36:27.895Z,1572474987.895 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:36:27.895Z,1572474987.895 [Default:A.Wait] Running Loop=1
2019-10-30T22:36:27.895Z,1572474987.895 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:36:29.155Z,1572474989.155 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004995
2019-10-30T22:36:32.361Z,1572474992.361 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2019-10-30T22:36:32.361Z,1572474992.361 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-10-30T22:36:32.361Z,1572474992.361 [RDI_Pathfinder](ERROR): Communications Fault
2019-10-30T22:36:32.361Z,1572474992.361 [RDI_Pathfinder](ERROR): Failed to parse:
2019-10-30T22:36:32.384Z,1572474992.384 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-10-30T22:36:32.753Z,1572474992.753 [RDI_Pathfinder](INFO): Powering down
2019-10-30T22:36:33.517Z,1572474993.517 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-10-30T22:36:33.517Z,1572474993.517 [RDI_Pathfinder] No Fault, FailCount= 1
2019-10-30T22:36:41.186Z,1572475001.186 [Default:A.Wait](INFO): Done Waiting.
2019-10-30T22:36:41.187Z,1572475001.187 [Default:A.Wait] Stopped
2019-10-30T22:36:41.187Z,1572475001.187 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:36:41.594Z,1572475001.594 [Default:CheckIn] Running Loop=1
2019-10-30T22:36:41.595Z,1572475001.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-30T22:36:41.595Z,1572475001.595 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-30T22:36:41.978Z,1572475001.978 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-30T22:36:46.825Z,1572475006.825 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-10-30T22:38:45.175Z,1572475125.175 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-10-30T22:38:45.997Z,1572475125.997 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:38:50.441Z,1572475130.441 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:38:53.669Z,1572475133.669 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:38:56.501Z,1572475136.501 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:38:59.745Z,1572475139.745 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:02.561Z,1572475142.561 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:05.393Z,1572475145.393 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:05.818Z,1572475145.818 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-10-30T22:39:05.818Z,1572475145.818 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-30T22:39:05.828Z,1572475145.828 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-30T22:39:06.324Z,1572475146.324 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-30T22:39:06.325Z,1572475146.325 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-10-30T22:39:07.414Z,1572475147.414 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:09.429Z,1572475149.429 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:12.661Z,1572475152.661 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:15.492Z,1572475155.492 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:18.732Z,1572475158.732 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:21.553Z,1572475161.553 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:23.944Z,1572475163.944 [CommandLine](IMPORTANT): got command failComponent
2019-10-30T22:39:23.958Z,1572475163.958 [CommandLine](IMPORTANT): Failed components:
2019-10-30T22:39:23.959Z,1572475163.959 [CommandLine](IMPORTANT): No failed Components.
2019-10-30T22:39:24.781Z,1572475164.781 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:27.159Z,1572475167.159 [CommandLine](IMPORTANT): got command show variable range
2019-10-30T22:39:27.162Z,1572475167.162 [CommandLine](IMPORTANT): acoustic_contact_range (unknown)
2019-10-30T22:39:27.315Z,1572475167.315 [CommandLine](IMPORTANT): BR_Ping1D.minRange (meter)
2019-10-30T22:39:27.316Z,1572475167.316 [CommandLine](IMPORTANT): BR_Ping1D.maxRange (meter)
2019-10-30T22:39:27.332Z,1572475167.332 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-10-30T22:39:27.333Z,1572475167.333 [CommandLine](IMPORTANT): Micromodem.range_request (count)
2019-10-30T22:39:27.334Z,1572475167.334 [CommandLine](IMPORTANT): Micromodem.range (meter)
2019-10-30T22:39:27.336Z,1572475167.336 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam1Range (meter)
2019-10-30T22:39:27.337Z,1572475167.337 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam2Range (meter)
2019-10-30T22:39:27.337Z,1572475167.337 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam3Range (meter)
2019-10-30T22:39:27.338Z,1572475167.338 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam4Range (meter)
2019-10-30T22:39:27.605Z,1572475167.605 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:30.441Z,1572475170.441 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:33.677Z,1572475173.677 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:35.825Z,1572475175.825 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.acoustic_contact_range
2019-10-30T22:39:36.505Z,1572475176.505 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:39.729Z,1572475179.729 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:40.163Z,1572475180.163 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-10-30T22:39:40.164Z,1572475180.164 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19103015500, -0.1,   0.0,1448.9,  0
2019-10-30T22:39:42.561Z,1572475182.561 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:45.385Z,1572475185.385 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:47.405Z,1572475187.405 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:49.425Z,1572475189.425 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:51.441Z,1572475191.441 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:54.681Z,1572475194.681 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:39:57.501Z,1572475197.501 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:00.742Z,1572475200.742 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:03.568Z,1572475203.568 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:06.393Z,1572475206.393 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:08.413Z,1572475208.413 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:10.433Z,1572475210.433 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:13.733Z,1572475213.733 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:16.533Z,1572475216.533 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:19.761Z,1572475219.761 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:20.634Z,1572475220.634 [DataOverHttps](IMPORTANT): SBD MTMSN=20191030T223915
2019-10-30T22:40:22.589Z,1572475222.589 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:25.412Z,1572475225.412 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:27.433Z,1572475227.433 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:28.361Z,1572475228.361 [DataOverHttps](INFO): Received command:load Maintenance/DUSBL_Tracking.xml;set DUSBL.TrackingUpdatePeriod 7 second;run 
2019-10-30T22:40:28.388Z,1572475228.388 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:40:28.389Z,1572475228.389 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:40:28.444Z,1572475228.444 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 10.000000 min
2019-10-30T22:40:28.467Z,1572475228.467 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-10-30T22:40:28.470Z,1572475228.470 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-10-30T22:40:28.474Z,1572475228.474 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-10-30T22:40:28.478Z,1572475228.478 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-10-30T22:40:28.480Z,1572475228.480 [DUSBL:A.Pitch](DEBUG): Construct.
2019-10-30T22:40:28.486Z,1572475228.486 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-10-30T22:40:28.654Z,1572475228.654 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-10-30T22:40:28.657Z,1572475228.657 [BPC1](INFO): Received data from all battery sticks.
2019-10-30T22:40:28.743Z,1572475228.743 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-10-30T22:40:28.773Z,1572475228.773 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

    <Description>
        This mission is requests a DUSBL arming.
    </Description>

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

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>4</Value></DefineArg>
    
    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    
    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>
    
      <Aggregate Id="RequestRepeater">

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

</Mission>


2019-10-30T22:40:28.775Z,1572475228.775 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:40:30.517Z,1572475230.517 [CommandLine](IMPORTANT): got command set DUSBL.TrackingUpdatePeriod 7.000000 second
2019-10-30T22:40:30.517Z,1572475230.517 [CommandLine](IMPORTANT): got command run 
2019-10-30T22:40:30.519Z,1572475230.519 [CommandLine](IMPORTANT): Running 
2019-10-30T22:40:30.665Z,1572475230.665 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:30.706Z,1572475230.706 [Default] Stopped
2019-10-30T22:40:30.706Z,1572475230.706 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-30T22:40:30.706Z,1572475230.706 [Default:B.GoToSurface] Stopped
2019-10-30T22:40:30.706Z,1572475230.706 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-30T22:40:30.706Z,1572475230.706 [Default:CheckIn] Stopped
2019-10-30T22:40:30.706Z,1572475230.706 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-30T22:40:30.706Z,1572475230.706 [Default:CheckIn:Read_GPS] Stopped
2019-10-30T22:40:30.707Z,1572475230.707 [MissionManager](IMPORTANT): Started mission DUSBL
2019-10-30T22:40:30.707Z,1572475230.707 [DUSBL] Running Loop=1
2019-10-30T22:40:30.707Z,1572475230.707 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-10-30T22:40:30.707Z,1572475230.707 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:40:30.707Z,1572475230.707 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-10-30T22:40:30.707Z,1572475230.707 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:40:30.707Z,1572475230.707 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-10-30T22:40:30.708Z,1572475230.708 [DUSBL:C.] Running Loop=1
2019-10-30T22:40:30.708Z,1572475230.708 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-10-30T22:40:30.708Z,1572475230.708 [DUSBL:RequestRepeater] Running Loop=1
2019-10-30T22:40:30.708Z,1572475230.708 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-10-30T22:40:30.708Z,1572475230.708 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-10-30T22:40:30.708Z,1572475230.708 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:40:30.709Z,1572475230.709 [DUSBL:C.] Running Loop=1
2019-10-30T22:40:30.710Z,1572475230.710 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:40:30.710Z,1572475230.710 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:40:33.493Z,1572475233.493 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:35.148Z,1572475235.148 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-10-30T22:40:35.148Z,1572475235.148 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19103015511371,35.0, -0.1,   0.0,1448.9A,  0.00,   0.00,   0.00,   0.00,   0.00
2019-10-30T22:40:36.725Z,1572475236.725 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:37.968Z,1572475237.968 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:40:38.326Z,1572475238.326 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:40:38.326Z,1572475238.326 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:40:38.327Z,1572475238.327 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:40:38.328Z,1572475238.328 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:40:38.732Z,1572475238.732 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
O
2019-10-30T22:40:38.732Z,1572475238.732 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:40:38.732Z,1572475238.732 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:40:38.734Z,1572475238.734 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:40:38.797Z,1572475238.797 [RDI_Pathfinder](ERROR): Failed to parse:
68,-32768,-32768,V
2019-10-30T22:40:39.149Z,1572475239.149 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:40:39.549Z,1572475239.549 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B89,000,0027D,189,80,80,47,FF
2019-10-30T22:40:39.550Z,1572475239.550 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:40:39.565Z,1572475239.565 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:39.689Z,1572475239.689 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:40:39.969Z,1572475239.969 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224039.74*53

2019-10-30T22:40:42.793Z,1572475242.793 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:45.617Z,1572475245.617 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:46.858Z,1572475246.858 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:40:47.214Z,1572475247.214 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:40:47.214Z,1572475247.214 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:40:47.214Z,1572475247.214 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:40:47.215Z,1572475247.215 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:40:47.619Z,1572475247.619 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B89,000,0027D,189,80,80,47,FF
2019-10-30T22:40:47.619Z,1572475247.619 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:40:47.619Z,1572475247.619 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:40:47.621Z,1572475247.621 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:40:48.025Z,1572475248.025 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:40:48.422Z,1572475248.422 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,BA3,000,0027C,18A,80,80,5A,FF
2019-10-30T22:40:48.423Z,1572475248.423 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:40:48.437Z,1572475248.437 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:48.527Z,1572475248.527 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:40:48.854Z,1572475248.854 [Micromodem](INFO): Nmea in: $SNTTA,,0.002072,,,224048.63*4A

2019-10-30T22:40:51.677Z,1572475251.677 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:54.501Z,1572475254.501 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:40:55.735Z,1572475255.735 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:40:56.100Z,1572475256.100 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:40:56.101Z,1572475256.101 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:40:56.101Z,1572475256.101 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:40:56.103Z,1572475256.103 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:40:56.510Z,1572475256.510 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
BA3,000,0027C,18A,80,80,5A,FF
2019-10-30T22:40:56.510Z,1572475256.510 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:40:56.511Z,1572475256.511 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:40:56.512Z,1572475256.512 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:40:56.909Z,1572475256.909 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:40:57.311Z,1572475257.311 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B93,000,0027D,189,80,80,5A,FF
2019-10-30T22:40:57.311Z,1572475257.311 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:40:57.386Z,1572475257.386 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:40:57.738Z,1572475257.738 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224057.52*5F

2019-10-30T22:40:57.766Z,1572475257.766 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:00.572Z,1572475260.572 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:03.389Z,1572475263.389 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:04.618Z,1572475264.618 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:41:04.986Z,1572475264.986 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:41:04.986Z,1572475264.986 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:41:04.986Z,1572475264.986 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:41:04.987Z,1572475264.987 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:41:05.394Z,1572475265.394 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B93,000,0027D,189,80,80,5A,FF
2019-10-30T22:41:05.395Z,1572475265.395 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:41:05.395Z,1572475265.395 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:41:05.396Z,1572475265.396 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:41:05.413Z,1572475265.413 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:05.797Z,1572475265.797 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:41:06.206Z,1572475266.206 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B74,000,0027B,189,80,80,57,FF
2019-10-30T22:41:06.207Z,1572475266.207 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:41:06.318Z,1572475266.318 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:41:06.626Z,1572475266.626 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224106.40*59

2019-10-30T22:41:07.446Z,1572475267.446 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:10.657Z,1572475270.657 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:13.489Z,1572475273.489 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:13.520Z,1572475273.520 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:41:13.878Z,1572475273.878 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:41:13.878Z,1572475273.878 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:41:13.879Z,1572475273.879 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:41:13.879Z,1572475273.879 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:41:14.288Z,1572475274.288 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B74,000,0027B,189,80,80,57,FF
2019-10-30T22:41:14.288Z,1572475274.288 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:41:14.288Z,1572475274.288 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:41:14.290Z,1572475274.290 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:41:14.701Z,1572475274.701 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:41:15.094Z,1572475275.094 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B93,000,0027C,189,80,80,52,FF
2019-10-30T22:41:15.095Z,1572475275.095 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:41:15.161Z,1572475275.161 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-10-30T22:41:15.200Z,1572475275.200 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:41:15.523Z,1572475275.523 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224115.29*54

2019-10-30T22:41:16.733Z,1572475276.733 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:19.562Z,1572475279.562 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:22.395Z,1572475282.395 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:41:22.762Z,1572475282.762 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:41:22.762Z,1572475282.762 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:41:22.762Z,1572475282.762 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:41:22.763Z,1572475282.763 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:41:22.781Z,1572475282.781 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:23.166Z,1572475283.166 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B93,000,0027C,189,80,80,52,FF
2019-10-30T22:41:23.167Z,1572475283.167 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:41:23.167Z,1572475283.167 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:41:23.169Z,1572475283.169 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:41:23.577Z,1572475283.577 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:41:23.983Z,1572475283.983 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B8E,000,0027C,18A,80,80,56,FF
2019-10-30T22:41:23.983Z,1572475283.983 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:41:24.074Z,1572475284.074 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:41:24.402Z,1572475284.402 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224124.17*5B

2019-10-30T22:41:25.613Z,1572475285.613 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:26.586Z,1572475286.586 [CommandLine](IMPORTANT): got command stop
2019-10-30T22:41:26.587Z,1572475286.587 [CommandLine](IMPORTANT): Scheduling is paused
2019-10-30T22:41:26.587Z,1572475286.587 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-30T22:41:26.867Z,1572475286.867 [MissionManager](INFO): MissionManager is completed.
2019-10-30T22:41:26.868Z,1572475286.868 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL] Stopped
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:A.Pitch] Stopped
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:B.SetSpeed] Stopped
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:C.] Stopped
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:RequestRepeater] Stopped
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-10-30T22:41:26.868Z,1572475286.868 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:41:27.239Z,1572475287.239 [MissionManager](IMPORTANT): Started mission Default
2019-10-30T22:41:27.239Z,1572475287.239 [Default] Running Loop=1
2019-10-30T22:41:27.239Z,1572475287.239 [Default](DEBUG): Aggregate::initialize Default
2019-10-30T22:41:27.239Z,1572475287.239 [Default:B.GoToSurface] Running Loop=1
2019-10-30T22:41:27.239Z,1572475287.239 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:41:27.239Z,1572475287.239 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:41:27.240Z,1572475287.240 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:41:27.240Z,1572475287.240 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:41:27.240Z,1572475287.240 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:41:27.257Z,1572475287.257 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:41:27.257Z,1572475287.257 [Default:A.Wait] Running Loop=1
2019-10-30T22:41:27.257Z,1572475287.257 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:41:28.433Z,1572475288.433 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:31.673Z,1572475291.673 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:34.493Z,1572475294.493 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:37.742Z,1572475297.742 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:40.556Z,1572475300.556 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:40.583Z,1572475300.583 [Default:A.Wait](INFO): Done Waiting.
2019-10-30T22:41:40.584Z,1572475300.583 [Default:A.Wait] Stopped
2019-10-30T22:41:40.584Z,1572475300.584 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:41:40.958Z,1572475300.958 [DataOverHttps](IMPORTANT): SBD MTMSN=20191030T224035
2019-10-30T22:41:41.025Z,1572475301.025 [Default:CheckIn] Running Loop=1
2019-10-30T22:41:41.025Z,1572475301.025 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-30T22:41:41.025Z,1572475301.025 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-30T22:41:43.385Z,1572475303.385 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:45.401Z,1572475305.401 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:47.425Z,1572475307.425 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:48.560Z,1572475308.560 [DataOverHttps](INFO): Received command:run Maintenance/DUSBL_Tracking.xml
2019-10-30T22:41:48.617Z,1572475308.617 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:41:48.618Z,1572475308.618 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:41:48.708Z,1572475308.708 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 10.000000 min
2019-10-30T22:41:48.714Z,1572475308.714 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-10-30T22:41:48.716Z,1572475308.716 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-10-30T22:41:48.721Z,1572475308.721 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-10-30T22:41:48.724Z,1572475308.724 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-10-30T22:41:48.726Z,1572475308.726 [DUSBL:A.Pitch](DEBUG): Construct.
2019-10-30T22:41:48.753Z,1572475308.753 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-10-30T22:41:48.826Z,1572475308.826 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-10-30T22:41:48.830Z,1572475308.830 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

    <Description>
        This mission is requests a DUSBL arming.
    </Description>

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

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>4</Value></DefineArg>
    
    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    
    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>
    
      <Aggregate Id="RequestRepeater">

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

</Mission>


2019-10-30T22:41:48.832Z,1572475308.832 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:41:49.081Z,1572475309.081 [Default] Stopped
2019-10-30T22:41:49.081Z,1572475309.081 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-30T22:41:49.081Z,1572475309.081 [Default:B.GoToSurface] Stopped
2019-10-30T22:41:49.081Z,1572475309.081 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-30T22:41:49.081Z,1572475309.081 [Default:CheckIn] Stopped
2019-10-30T22:41:49.081Z,1572475309.081 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-30T22:41:49.081Z,1572475309.081 [Default:CheckIn:Read_GPS] Stopped
2019-10-30T22:41:49.082Z,1572475309.082 [MissionManager](IMPORTANT): Started mission DUSBL
2019-10-30T22:41:49.082Z,1572475309.082 [DUSBL] Running Loop=1
2019-10-30T22:41:49.082Z,1572475309.082 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-10-30T22:41:49.082Z,1572475309.082 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:41:49.082Z,1572475309.082 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-10-30T22:41:49.082Z,1572475309.082 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:41:49.082Z,1572475309.082 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-10-30T22:41:49.082Z,1572475309.082 [DUSBL:C.] Running Loop=1
2019-10-30T22:41:49.083Z,1572475309.083 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-10-30T22:41:49.083Z,1572475309.083 [DUSBL:RequestRepeater] Running Loop=1
2019-10-30T22:41:49.083Z,1572475309.083 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-10-30T22:41:49.083Z,1572475309.083 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-10-30T22:41:49.083Z,1572475309.083 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:41:49.083Z,1572475309.083 [DUSBL:C.] Running Loop=1
2019-10-30T22:41:49.084Z,1572475309.084 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:41:49.084Z,1572475309.084 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:41:49.453Z,1572475309.453 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:52.673Z,1572475312.673 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:53.133Z,1572475313.133 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:41:53.476Z,1572475313.476 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:41:53.476Z,1572475313.476 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:41:53.476Z,1572475313.476 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:41:53.520Z,1572475313.520 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:41:53.520Z,1572475313.520 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B8E,000,0027C,18A,80,80,56,FF
2019-10-30T22:41:53.520Z,1572475313.520 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:41:53.520Z,1572475313.520 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:41:53.522Z,1572475313.523 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:41:53.878Z,1572475313.878 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:41:54.280Z,1572475314.280 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B8E,000,0027E,189,80,80,52,FF
2019-10-30T22:41:54.281Z,1572475314.281 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:41:54.367Z,1572475314.367 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.780000 m
2019-10-30T22:41:55.117Z,1572475315.117 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224154.53*5C

2019-10-30T22:41:55.509Z,1572475315.509 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:58.351Z,1572475318.351 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:41:58.718Z,1572475318.718 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:41:58.718Z,1572475318.718 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:41:58.719Z,1572475318.719 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:41:58.719Z,1572475318.719 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:41:58.737Z,1572475318.737 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:41:59.131Z,1572475319.131 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B8E,000,0027E,189,80,80,52,FF
2019-10-30T22:41:59.131Z,1572475319.131 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:41:59.131Z,1572475319.131 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:41:59.132Z,1572475319.132 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:41:59.537Z,1572475319.537 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:41:59.940Z,1572475319.940 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B7F,000,0027D,189,80,80,5D,FF
2019-10-30T22:41:59.940Z,1572475319.940 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:42:00.010Z,1572475320.010 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:42:00.357Z,1572475320.357 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224200.14*5D

2019-10-30T22:42:01.581Z,1572475321.581 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:04.018Z,1572475324.018 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:42:04.378Z,1572475324.378 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:42:04.378Z,1572475324.378 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:42:04.378Z,1572475324.378 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:42:04.379Z,1572475324.379 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:42:04.786Z,1572475324.786 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B7F,000,0027D,189,80,80,5D,FF
2019-10-30T22:42:04.786Z,1572475324.786 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:42:04.787Z,1572475324.787 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:42:04.788Z,1572475324.788 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:42:04.810Z,1572475324.810 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:05.193Z,1572475325.193 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:42:05.590Z,1572475325.590 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B61,000,0027A,18A,80,80,57,FF
2019-10-30T22:42:05.591Z,1572475325.591 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:42:05.689Z,1572475325.689 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:42:06.014Z,1572475326.014 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224205.80*55

2019-10-30T22:42:06.855Z,1572475326.855 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-10-30T22:42:06.855Z,1572475326.855 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-30T22:42:06.880Z,1572475326.880 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-30T22:42:07.266Z,1572475327.266 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-30T22:42:07.266Z,1572475327.266 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-10-30T22:42:07.641Z,1572475327.641 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:10.073Z,1572475330.073 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:42:10.438Z,1572475330.438 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:42:10.438Z,1572475330.438 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:42:10.438Z,1572475330.438 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:42:10.439Z,1572475330.439 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:42:10.457Z,1572475330.457 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:10.848Z,1572475330.848 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B61,000,0027A,18A,80,80,57,FF
2019-10-30T22:42:10.848Z,1572475330.848 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:42:10.848Z,1572475330.848 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:42:10.850Z,1572475330.850 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:42:11.249Z,1572475331.249 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:42:11.657Z,1572475331.657 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B77,000,0027B,189,80,80,58,FF
2019-10-30T22:42:11.658Z,1572475331.658 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:42:11.730Z,1572475331.730 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:42:12.074Z,1572475332.074 [Micromodem](INFO): Nmea in: $SNTTA,0.186133,,,,224211.86*46

2019-10-30T22:42:13.709Z,1572475333.709 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:15.728Z,1572475335.728 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:42:16.100Z,1572475336.100 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-10-30T22:42:16.100Z,1572475336.100 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-10-30T22:42:16.101Z,1572475336.101 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 25
2019-10-30T22:42:16.102Z,1572475336.102 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-10-30T22:42:16.509Z,1572475336.509 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
B77,000,0027B,189,80,80,58,FF
2019-10-30T22:42:16.509Z,1572475336.509 [DUSBL_Hydroid](INFO): Command Ack
2019-10-30T22:42:16.509Z,1572475336.509 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-10-30T22:42:16.511Z,1572475336.511 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:42:16.525Z,1572475336.525 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:16.905Z,1572475336.905 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:42:17.307Z,1572475337.307 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,B5A,000,0027C,189,80,80,59,FF
2019-10-30T22:42:17.307Z,1572475337.307 [DUSBL_Hydroid](INFO): publishing direction and range info
2019-10-30T22:42:17.411Z,1572475337.411 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:42:17.735Z,1572475337.735 [Micromodem](INFO): Nmea in: $SNTTA,0.000100,,,,224217.52*46

2019-10-30T22:42:19.769Z,1572475339.769 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:20.772Z,1572475340.772 [CommandLine](IMPORTANT): got command stop
2019-10-30T22:42:20.773Z,1572475340.773 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-30T22:42:20.990Z,1572475340.990 [MissionManager](INFO): MissionManager is completed.
2019-10-30T22:42:20.990Z,1572475340.990 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL] Stopped
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL:A.Pitch] Stopped
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL:B.SetSpeed] Stopped
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL:C.] Stopped
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL:RequestRepeater] Stopped
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-10-30T22:42:20.990Z,1572475340.990 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-10-30T22:42:20.991Z,1572475340.991 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:42:21.390Z,1572475341.390 [MissionManager](IMPORTANT): Started mission Default
2019-10-30T22:42:21.390Z,1572475341.390 [Default] Running Loop=1
2019-10-30T22:42:21.390Z,1572475341.390 [Default](DEBUG): Aggregate::initialize Default
2019-10-30T22:42:21.390Z,1572475341.390 [Default:B.GoToSurface] Running Loop=1
2019-10-30T22:42:21.390Z,1572475341.390 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:42:21.391Z,1572475341.391 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:42:21.391Z,1572475341.391 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:42:21.391Z,1572475341.391 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:42:21.392Z,1572475341.392 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:42:21.392Z,1572475341.392 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:42:21.392Z,1572475341.392 [Default:A.Wait] Running Loop=1
2019-10-30T22:42:21.393Z,1572475341.393 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:42:22.597Z,1572475342.597 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:23.544Z,1572475343.544 [CommandLine](IMPORTANT): got command show variable DUSBL
2019-10-30T22:42:23.611Z,1572475343.611 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-10-30T22:42:23.611Z,1572475343.611 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-10-30T22:42:23.611Z,1572475343.611 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (second)
2019-10-30T22:42:23.612Z,1572475343.612 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-10-30T22:42:23.612Z,1572475343.612 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-10-30T22:42:23.612Z,1572475343.612 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-10-30T22:42:23.613Z,1572475343.613 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-10-30T22:42:23.614Z,1572475343.614 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-10-30T22:42:23.614Z,1572475343.614 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-10-30T22:42:23.614Z,1572475343.614 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-10-30T22:42:23.615Z,1572475343.615 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-10-30T22:42:23.615Z,1572475343.615 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-10-30T22:42:23.618Z,1572475343.618 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (none)
2019-10-30T22:42:23.629Z,1572475343.629 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-10-30T22:42:23.629Z,1572475343.629 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-10-30T22:42:23.629Z,1572475343.629 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-10-30T22:42:23.634Z,1572475343.634 [CommandLine](IMPORTANT): Micromodem.dusblPingCodeRequested (enum)
2019-10-30T22:42:23.634Z,1572475343.634 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-10-30T22:42:23.634Z,1572475343.634 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-10-30T22:42:23.635Z,1572475343.635 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-10-30T22:42:23.635Z,1572475343.635 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-10-30T22:42:23.635Z,1572475343.635 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-10-30T22:42:23.636Z,1572475343.636 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-10-30T22:42:23.636Z,1572475343.636 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-10-30T22:42:23.636Z,1572475343.636 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-10-30T22:42:23.637Z,1572475343.637 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_direction_vehicle_frame (none)
2019-10-30T22:42:23.637Z,1572475343.637 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_address (enum)
2019-10-30T22:42:23.659Z,1572475343.659 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_voltage (volt)
2019-10-30T22:42:23.660Z,1572475343.660 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgVoltage (volt)
2019-10-30T22:42:23.660Z,1572475343.660 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_current (milliampere)
2019-10-30T22:42:23.660Z,1572475343.660 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgCurrent (milliampere)
2019-10-30T22:42:25.401Z,1572475345.401 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:27.425Z,1572475347.425 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:29.453Z,1572475349.453 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:32.673Z,1572475352.673 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:34.727Z,1572475354.727 [Default:A.Wait](INFO): Done Waiting.
2019-10-30T22:42:34.727Z,1572475354.727 [Default:A.Wait] Stopped
2019-10-30T22:42:34.727Z,1572475354.727 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:42:35.145Z,1572475355.145 [Default:CheckIn] Running Loop=1
2019-10-30T22:42:35.145Z,1572475355.145 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-30T22:42:35.145Z,1572475355.145 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-30T22:42:35.501Z,1572475355.501 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:38.733Z,1572475358.733 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:41.146Z,1572475361.146 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.verbosity 0.000000 enum persist
2019-10-30T22:42:41.561Z,1572475361.561 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:44.385Z,1572475364.385 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:46.413Z,1572475366.413 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:48.429Z,1572475368.429 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:51.384Z,1572475371.384 [CommandLine](IMPORTANT): got command failComponent hardware DUSBL_Hydroid
2019-10-30T22:42:51.384Z,1572475371.384 [DUSBL_Hydroid] Hardware Fault, FailCount= 1
2019-10-30T22:42:51.384Z,1572475371.384 [DUSBL_Hydroid](ERROR): Hardware Fault
2019-10-30T22:42:51.385Z,1572475371.385 [CommandLine](IMPORTANT): DUSBL_Hydroid failureMode is Hardware Fault
2019-10-30T22:42:51.642Z,1572475371.642 [DUSBL_Hydroid](INFO): Powering down
2019-10-30T22:42:51.729Z,1572475371.729 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:51.809Z,1572475371.809 [CBIT](ERROR): Hardware Fault in component: DUSBL_Hydroid
2019-10-30T22:42:52.507Z,1572475372.507 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid
2019-10-30T22:42:52.507Z,1572475372.507 [DUSBL_Hydroid] No Fault, FailCount= 1
2019-10-30T22:42:54.489Z,1572475374.489 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:42:54.878Z,1572475374.878 [DUSBL_Hydroid](INFO): Powering up
2019-10-30T22:42:54.878Z,1572475374.878 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-10-30T22:42:56.934Z,1572475376.934 [RDI_Pathfinder](ERROR): Failed to parse:
:SA,   +0.00,   +0.00,  0.00
2019-10-30T22:42:57.733Z,1572475377.733 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:00.549Z,1572475380.549 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:03.377Z,1572475383.377 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:05.397Z,1572475385.397 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:07.421Z,1572475387.421 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:09.435Z,1572475389.435 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:12.669Z,1572475392.669 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:13.058Z,1572475393.058 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-10-30T22:43:15.497Z,1572475395.497 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:18.733Z,1572475398.733 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:21.557Z,1572475401.557 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:24.385Z,1572475404.385 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:26.401Z,1572475406.401 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:28.425Z,1572475408.425 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:31.669Z,1572475411.669 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:34.481Z,1572475414.481 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:36.513Z,1572475416.513 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-10-30T22:43:36.513Z,1572475416.513 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19103015541471,35,   0.0,1448.9,  0
2019-10-30T22:43:37.054Z,1572475417.054 [DataOverHttps](IMPORTANT): SBD MTMSN=20191030T224231
2019-10-30T22:43:37.721Z,1572475417.721 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:40.160Z,1572475420.160 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-10-30T22:43:40.160Z,1572475420.160 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,191030155.0, -0.1,   0.0,1448.9,  0
2019-10-30T22:43:40.541Z,1572475420.541 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:43:42.178Z,1572475422.178 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-10-30T22:43:42.178Z,1572475422.178 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-10-30T22:43:43.763Z,1572475423.763 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-10-30T22:43:43.763Z,1572475423.763 [NAL9602] Data Fault, FailCount= 1
2019-10-30T22:43:43.763Z,1572475423.763 [NAL9602](ERROR): Data Fault
2019-10-30T22:43:43.833Z,1572475423.833 [CBIT](ERROR): Data Fault in component: NAL9602
2019-10-30T22:43:44.167Z,1572475424.167 [NAL9602](INFO): Powering down
2019-10-30T22:43:44.624Z,1572475424.624 [DataOverHttps](INFO): Received command:run Maintenance/DUSBL_Tracking.xml
2019-10-30T22:43:44.645Z,1572475424.645 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:43:44.646Z,1572475424.646 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:43:44.701Z,1572475424.701 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 10.000000 min
2019-10-30T22:43:44.704Z,1572475424.704 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-10-30T22:43:44.710Z,1572475424.710 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-10-30T22:43:44.712Z,1572475424.712 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-10-30T22:43:44.726Z,1572475424.726 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-10-30T22:43:44.727Z,1572475424.727 [DUSBL:A.Pitch](DEBUG): Construct.
2019-10-30T22:43:44.744Z,1572475424.744 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-10-30T22:43:44.799Z,1572475424.799 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-10-30T22:43:44.807Z,1572475424.807 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

    <Description>
        This mission is requests a DUSBL arming.
    </Description>

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

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>4</Value></DefineArg>
    
    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    
    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>
    
      <Aggregate Id="RequestRepeater">

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

</Mission>


2019-10-30T22:43:44.813Z,1572475424.813 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:43:45.011Z,1572475425.011 [Default] Stopped
2019-10-30T22:43:45.011Z,1572475425.011 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-30T22:43:45.011Z,1572475425.011 [Default:B.GoToSurface] Stopped
2019-10-30T22:43:45.011Z,1572475425.011 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-30T22:43:45.011Z,1572475425.011 [Default:CheckIn] Stopped
2019-10-30T22:43:45.011Z,1572475425.011 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-30T22:43:45.011Z,1572475425.011 [Default:CheckIn:Read_GPS] Stopped
2019-10-30T22:43:45.011Z,1572475425.011 [MissionManager](IMPORTANT): Started mission DUSBL
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL] Running Loop=1
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL:C.] Running Loop=1
2019-10-30T22:43:45.012Z,1572475425.012 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-10-30T22:43:45.013Z,1572475425.013 [DUSBL:RequestRepeater] Running Loop=1
2019-10-30T22:43:45.013Z,1572475425.013 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-10-30T22:43:45.013Z,1572475425.013 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-10-30T22:43:45.013Z,1572475425.013 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:43:45.014Z,1572475425.014 [DUSBL:C.] Running Loop=1
2019-10-30T22:43:45.014Z,1572475425.014 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:43:45.014Z,1572475425.014 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:43:45.022Z,1572475425.022 [CBIT](INFO): Clearing failed state for component NAL9602
2019-10-30T22:43:45.022Z,1572475425.022 [NAL9602] No Fault, FailCount= 1
2019-10-30T22:43:49.054Z,1572475429.054 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:43:49.828Z,1572475429.828 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:43:50.225Z,1572475430.225 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:43:50.683Z,1572475430.683 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:43:51.054Z,1572475431.054 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224350.83*57

2019-10-30T22:43:54.697Z,1572475434.697 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:43:55.476Z,1572475435.476 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:43:55.881Z,1572475435.881 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:43:56.356Z,1572475436.356 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:43:56.710Z,1572475436.710 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224356.48*56

2019-10-30T22:44:00.358Z,1572475440.358 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:01.132Z,1572475441.132 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:01.541Z,1572475441.541 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:02.013Z,1572475442.013 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:44:02.362Z,1572475442.362 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224402.14*59

2019-10-30T22:44:06.015Z,1572475446.015 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:06.804Z,1572475446.804 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:07.197Z,1572475447.197 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:07.640Z,1572475447.640 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:44:08.026Z,1572475448.026 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224407.81*50

2019-10-30T22:44:11.663Z,1572475451.663 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:12.447Z,1572475452.447 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:12.873Z,1572475452.873 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:13.314Z,1572475453.314 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:44:13.678Z,1572475453.678 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224413.45*5D

2019-10-30T22:44:14.496Z,1572475454.496 [NAL9602](INFO): Powering up NAL9602
2019-10-30T22:44:17.346Z,1572475457.346 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:18.107Z,1572475458.107 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:18.509Z,1572475458.509 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:18.994Z,1572475458.994 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:44:19.327Z,1572475459.327 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224419.12*55

2019-10-30T22:44:22.987Z,1572475462.987 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:23.144Z,1572475463.144 [CommandLine](IMPORTANT): got command show variable DUSBL
2019-10-30T22:44:23.191Z,1572475463.191 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-10-30T22:44:23.191Z,1572475463.191 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-10-30T22:44:23.192Z,1572475463.192 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (second)
2019-10-30T22:44:23.192Z,1572475463.192 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-10-30T22:44:23.192Z,1572475463.192 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-10-30T22:44:23.193Z,1572475463.193 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-10-30T22:44:23.193Z,1572475463.193 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-10-30T22:44:23.194Z,1572475463.194 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-10-30T22:44:23.194Z,1572475463.194 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-10-30T22:44:23.194Z,1572475463.194 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-10-30T22:44:23.195Z,1572475463.195 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-10-30T22:44:23.195Z,1572475463.195 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-10-30T22:44:23.198Z,1572475463.198 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (none)
2019-10-30T22:44:23.209Z,1572475463.209 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-10-30T22:44:23.209Z,1572475463.209 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-10-30T22:44:23.209Z,1572475463.209 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-10-30T22:44:23.213Z,1572475463.213 [CommandLine](IMPORTANT): DUSBL_Hydroid.pingRequested (count)
2019-10-30T22:44:23.213Z,1572475463.213 [CommandLine](IMPORTANT): Micromodem.dusblPingCodeRequested (enum)
2019-10-30T22:44:23.214Z,1572475463.214 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-10-30T22:44:23.214Z,1572475463.214 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-10-30T22:44:23.214Z,1572475463.214 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-10-30T22:44:23.215Z,1572475463.215 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-10-30T22:44:23.215Z,1572475463.215 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-10-30T22:44:23.215Z,1572475463.215 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-10-30T22:44:23.216Z,1572475463.216 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-10-30T22:44:23.216Z,1572475463.216 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-10-30T22:44:23.216Z,1572475463.216 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_direction_vehicle_frame (none)
2019-10-30T22:44:23.249Z,1572475463.249 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_address (enum)
2019-10-30T22:44:23.335Z,1572475463.335 [CommandLine](IMPORTANT): DUSBL.MissionTimeout (minute)
2019-10-30T22:44:23.335Z,1572475463.335 [CommandLine](IMPORTANT): DUSBL.TransponderCode (count)
2019-10-30T22:44:23.335Z,1572475463.335 [CommandLine](IMPORTANT): DUSBL.TrackingUpdatePeriod (second)
2019-10-30T22:44:23.336Z,1572475463.336 [CommandLine](IMPORTANT): DUSBL.NumberOfPings (count)
2019-10-30T22:44:23.336Z,1572475463.336 [CommandLine](IMPORTANT): DUSBL.EnabledDUSBL (none)
2019-10-30T22:44:23.375Z,1572475463.375 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_voltage (volt)
2019-10-30T22:44:23.385Z,1572475463.385 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgVoltage (volt)
2019-10-30T22:44:23.386Z,1572475463.386 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_current (milliampere)
2019-10-30T22:44:23.386Z,1572475463.386 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgCurrent (milliampere)
2019-10-30T22:44:23.760Z,1572475463.760 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:24.161Z,1572475464.161 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:24.611Z,1572475464.611 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:44:24.990Z,1572475464.990 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224424.77*58

2019-10-30T22:44:25.383Z,1572475465.383 [NAL9602](INFO): NAL9602 initialized
2019-10-30T22:44:26.213Z,1572475466.213 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:28.643Z,1572475468.643 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:29.025Z,1572475469.025 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:29.416Z,1572475469.416 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:29.825Z,1572475469.825 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:30.274Z,1572475470.274 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:44:30.646Z,1572475470.646 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224430.42*5B

2019-10-30T22:44:31.857Z,1572475471.857 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:34.305Z,1572475474.305 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:35.072Z,1572475475.072 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:35.097Z,1572475475.097 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:35.473Z,1572475475.473 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:35.954Z,1572475475.954 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:44:36.304Z,1572475476.304 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224436.08*53

2019-10-30T22:44:37.929Z,1572475477.929 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:39.960Z,1572475479.960 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:40.732Z,1572475480.732 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:41.129Z,1572475481.129 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:41.153Z,1572475481.153 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:41.176Z,1572475481.176 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-10-30T22:44:41.599Z,1572475481.599 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:44:41.962Z,1572475481.962 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224441.74*58

2019-10-30T22:44:43.989Z,1572475483.989 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:45.606Z,1572475485.606 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:46.384Z,1572475486.384 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:46.805Z,1572475486.805 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:46.829Z,1572475486.829 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:47.250Z,1572475487.250 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:44:47.614Z,1572475487.614 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224447.39*57

2019-10-30T22:44:50.041Z,1572475490.041 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:50.948Z,1572475490.948 [CommandLine](IMPORTANT): got command show variable dusbl
2019-10-30T22:44:50.998Z,1572475490.998 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-10-30T22:44:50.999Z,1572475490.999 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-10-30T22:44:50.999Z,1572475490.999 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (second)
2019-10-30T22:44:50.999Z,1572475490.999 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-10-30T22:44:50.000Z,1572475491.000 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-10-30T22:44:50.000Z,1572475491.000 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-10-30T22:44:51.000Z,1572475491.000 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-10-30T22:44:51.001Z,1572475491.001 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-10-30T22:44:51.001Z,1572475491.001 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-10-30T22:44:51.002Z,1572475491.001 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-10-30T22:44:51.002Z,1572475491.002 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-10-30T22:44:51.002Z,1572475491.002 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-10-30T22:44:51.037Z,1572475491.037 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (none)
2019-10-30T22:44:51.073Z,1572475491.073 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-10-30T22:44:51.074Z,1572475491.074 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-10-30T22:44:51.074Z,1572475491.074 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-10-30T22:44:51.103Z,1572475491.103 [CommandLine](IMPORTANT): DUSBL_Hydroid.pingRequested (count)
2019-10-30T22:44:51.104Z,1572475491.104 [CommandLine](IMPORTANT): Micromodem.dusblPingCodeRequested (enum)
2019-10-30T22:44:51.104Z,1572475491.104 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-10-30T22:44:51.104Z,1572475491.104 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-10-30T22:44:51.118Z,1572475491.118 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-10-30T22:44:51.119Z,1572475491.119 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-10-30T22:44:51.119Z,1572475491.119 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-10-30T22:44:51.120Z,1572475491.120 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-10-30T22:44:51.120Z,1572475491.120 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-10-30T22:44:51.120Z,1572475491.120 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-10-30T22:44:51.121Z,1572475491.121 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_direction_vehicle_frame (none)
2019-10-30T22:44:51.121Z,1572475491.121 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_address (enum)
2019-10-30T22:44:51.195Z,1572475491.195 [CommandLine](IMPORTANT): DUSBL.MissionTimeout (minute)
2019-10-30T22:44:51.195Z,1572475491.195 [CommandLine](IMPORTANT): DUSBL.TransponderCode (count)
2019-10-30T22:44:51.196Z,1572475491.196 [CommandLine](IMPORTANT): DUSBL.TrackingUpdatePeriod (second)
2019-10-30T22:44:51.196Z,1572475491.196 [CommandLine](IMPORTANT): DUSBL.NumberOfPings (count)
2019-10-30T22:44:51.196Z,1572475491.196 [CommandLine](IMPORTANT): DUSBL.EnabledDUSBL (none)
2019-10-30T22:44:51.198Z,1572475491.198 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_voltage (volt)
2019-10-30T22:44:51.198Z,1572475491.198 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgVoltage (volt)
2019-10-30T22:44:51.198Z,1572475491.198 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_current (milliampere)
2019-10-30T22:44:51.199Z,1572475491.199 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgCurrent (milliampere)
2019-10-30T22:44:51.283Z,1572475491.283 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:52.052Z,1572475492.052 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:52.453Z,1572475492.453 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:52.881Z,1572475492.881 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:52.981Z,1572475492.981 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:44:53.278Z,1572475493.278 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224453.06*5E

2019-10-30T22:44:56.101Z,1572475496.101 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:57.319Z,1572475497.319 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:44:58.100Z,1572475498.100 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:44:58.505Z,1572475498.505 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:44:58.929Z,1572475498.929 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:44:59.007Z,1572475499.007 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:44:59.330Z,1572475499.330 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224459.11*52

2019-10-30T22:45:02.153Z,1572475502.153 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:03.002Z,1572475503.002 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:03.756Z,1572475503.756 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:04.161Z,1572475504.161 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:04.642Z,1572475504.642 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:45:04.704Z,1572475504.704 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.xCenter
2019-10-30T22:45:04.990Z,1572475504.990 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224504.76*5A

2019-10-30T22:45:05.005Z,1572475505.005 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:07.817Z,1572475507.817 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:07.857Z,1572475507.857 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-10-30T22:45:07.857Z,1572475507.857 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-30T22:45:07.873Z,1572475507.873 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-30T22:45:08.264Z,1572475508.264 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-30T22:45:08.264Z,1572475508.264 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-10-30T22:45:08.650Z,1572475508.650 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:09.408Z,1572475509.408 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:09.827Z,1572475509.827 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:09.853Z,1572475509.853 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:10.294Z,1572475510.294 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:45:10.642Z,1572475510.642 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224510.42*58

2019-10-30T22:45:13.065Z,1572475513.065 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:14.292Z,1572475514.292 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:15.068Z,1572475515.068 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:15.469Z,1572475515.469 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:15.508Z,1572475515.508 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-10-30T22:45:15.508Z,1572475515.508 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-10-30T22:45:15.897Z,1572475515.897 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:15.959Z,1572475515.959 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:45:16.298Z,1572475516.298 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224516.07*5F

2019-10-30T22:45:19.121Z,1572475519.121 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:19.965Z,1572475519.965 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:20.732Z,1572475520.732 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:21.125Z,1572475521.125 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:21.164Z,1572475521.164 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-10-30T22:45:21.183Z,1572475521.183 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-10-30T22:45:21.603Z,1572475521.603 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:45:21.951Z,1572475521.951 [Micromodem](INFO): Nmea in: $SNTTA,0.000069,,,,224521.74*4E

2019-10-30T22:45:21.965Z,1572475521.965 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:25.181Z,1572475525.181 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:25.627Z,1572475525.627 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:26.392Z,1572475526.392 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:26.810Z,1572475526.810 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:27.247Z,1572475527.247 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:45:27.642Z,1572475527.642 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224527.40*5E

2019-10-30T22:45:28.037Z,1572475528.037 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:30.837Z,1572475530.837 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:31.278Z,1572475531.278 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:31.333Z,1572475531.333 [CommandLine](IMPORTANT): got command report
2019-10-30T22:45:31.333Z,1572475531.333 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range reporting when touched
2019-10-30T22:45:31.334Z,1572475531.334 [Reporter](INFO): DUSBL_Hydroid.xCenter reporting when touched
2019-10-30T22:45:32.040Z,1572475532.040 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:32.441Z,1572475532.441 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:32.914Z,1572475532.914 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:45:33.266Z,1572475533.266 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224533.05*5A

2019-10-30T22:45:34.081Z,1572475534.081 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:36.901Z,1572475536.901 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:36.932Z,1572475536.932 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:37.692Z,1572475537.692 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:38.103Z,1572475538.103 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:38.552Z,1572475538.552 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:45:38.918Z,1572475538.918 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224538.69*5B

2019-10-30T22:45:40.145Z,1572475540.145 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:41.625Z,1572475541.625 [CommandLine](IMPORTANT): got command show variable dusbl
2019-10-30T22:45:41.674Z,1572475541.674 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-10-30T22:45:41.675Z,1572475541.675 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-10-30T22:45:41.675Z,1572475541.675 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (second)
2019-10-30T22:45:41.675Z,1572475541.675 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-10-30T22:45:41.676Z,1572475541.676 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-10-30T22:45:41.676Z,1572475541.676 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-10-30T22:45:41.677Z,1572475541.677 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-10-30T22:45:41.677Z,1572475541.677 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-10-30T22:45:41.677Z,1572475541.677 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-10-30T22:45:41.678Z,1572475541.678 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-10-30T22:45:41.678Z,1572475541.678 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-10-30T22:45:41.678Z,1572475541.678 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-10-30T22:45:41.681Z,1572475541.681 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (none)
2019-10-30T22:45:41.820Z,1572475541.820 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-10-30T22:45:41.820Z,1572475541.820 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-10-30T22:45:41.820Z,1572475541.820 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-10-30T22:45:41.836Z,1572475541.836 [CommandLine](IMPORTANT): DUSBL_Hydroid.pingRequested (count)
2019-10-30T22:45:41.849Z,1572475541.849 [CommandLine](IMPORTANT): Micromodem.dusblPingCodeRequested (enum)
2019-10-30T22:45:41.854Z,1572475541.854 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-10-30T22:45:41.855Z,1572475541.855 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-10-30T22:45:41.855Z,1572475541.855 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-10-30T22:45:41.855Z,1572475541.855 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-10-30T22:45:41.856Z,1572475541.856 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-10-30T22:45:41.856Z,1572475541.856 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-10-30T22:45:41.856Z,1572475541.856 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-10-30T22:45:41.857Z,1572475541.857 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-10-30T22:45:41.857Z,1572475541.857 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_direction_vehicle_frame (none)
2019-10-30T22:45:41.858Z,1572475541.858 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_address (enum)
2019-10-30T22:45:41.927Z,1572475541.927 [CommandLine](IMPORTANT): DUSBL.MissionTimeout (minute)
2019-10-30T22:45:41.928Z,1572475541.928 [CommandLine](IMPORTANT): DUSBL.TransponderCode (count)
2019-10-30T22:45:41.928Z,1572475541.928 [CommandLine](IMPORTANT): DUSBL.TrackingUpdatePeriod (second)
2019-10-30T22:45:41.928Z,1572475541.928 [CommandLine](IMPORTANT): DUSBL.NumberOfPings (count)
2019-10-30T22:45:41.937Z,1572475541.937 [CommandLine](IMPORTANT): DUSBL.EnabledDUSBL (none)
2019-10-30T22:45:41.938Z,1572475541.938 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_voltage (volt)
2019-10-30T22:45:41.938Z,1572475541.938 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgVoltage (volt)
2019-10-30T22:45:41.939Z,1572475541.939 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_current (milliampere)
2019-10-30T22:45:41.939Z,1572475541.939 [CommandLine](IMPORTANT): DUSBL_Hydroid.component_avgCurrent (milliampere)
2019-10-30T22:45:42.572Z,1572475542.572 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:42.961Z,1572475542.961 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:43.344Z,1572475543.344 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:43.757Z,1572475543.757 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:44.213Z,1572475544.213 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:45:44.574Z,1572475544.574 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224544.35*59

2019-10-30T22:45:45.793Z,1572475545.793 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:47.805Z,1572475547.805 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:48.235Z,1572475548.235 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:49.004Z,1572475549.004 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:49.405Z,1572475549.405 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:49.833Z,1572475549.833 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:49.911Z,1572475549.911 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:45:50.234Z,1572475550.234 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224550.01*5B

2019-10-30T22:45:53.057Z,1572475553.057 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:53.903Z,1572475553.903 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:45:54.667Z,1572475554.667 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:45:55.061Z,1572475555.061 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:45:55.536Z,1572475555.536 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:45:55.890Z,1572475555.890 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224555.67*5E

2019-10-30T22:45:55.911Z,1572475555.911 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:59.113Z,1572475559.113 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:45:59.569Z,1572475559.569 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:00.316Z,1572475560.316 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:00.725Z,1572475560.725 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:46:00.802Z,1572475560.802 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-10-30T22:46:00.803Z,1572475560.803 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,32768,-32768,V
2019-10-30T22:46:01.183Z,1572475561.183 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:46:01.554Z,1572475561.554 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224601.32*5C

2019-10-30T22:46:01.965Z,1572475561.965 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:03.419Z,1572475563.419 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.xAngle
2019-10-30T22:46:04.773Z,1572475564.773 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:05.253Z,1572475565.253 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:05.972Z,1572475565.972 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:06.377Z,1572475566.377 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:46:06.817Z,1572475566.817 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:06.936Z,1572475566.936 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:46:06.936Z,1572475566.936 [Reporter](INFO): DUSBL_Hydroid.xAngle 57.899999 arcdeg
2019-10-30T22:46:07.198Z,1572475567.198 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224606.98*5B

2019-10-30T22:46:08.829Z,1572475568.829 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:10.845Z,1572475570.845 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:10.915Z,1572475570.915 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:11.632Z,1572475571.632 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:12.033Z,1572475572.033 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:46:12.527Z,1572475572.527 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:46:12.527Z,1572475572.527 [Reporter](INFO): DUSBL_Hydroid.xAngle 59.350000 arcdeg
2019-10-30T22:46:12.870Z,1572475572.870 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224612.63*5A

2019-10-30T22:46:14.077Z,1572475574.077 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:16.511Z,1572475576.511 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:16.893Z,1572475576.893 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:17.287Z,1572475577.287 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:17.693Z,1572475577.693 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:46:18.164Z,1572475578.164 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:46:18.169Z,1572475578.169 [Reporter](INFO): DUSBL_Hydroid.xAngle 57.699997 arcdeg
2019-10-30T22:46:18.514Z,1572475578.514 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224618.29*5E

2019-10-30T22:46:20.142Z,1572475580.142 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:22.164Z,1572475582.164 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:22.940Z,1572475582.940 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:22.961Z,1572475582.961 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:23.341Z,1572475583.341 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:46:23.814Z,1572475583.814 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:46:23.815Z,1572475583.815 [Reporter](INFO): DUSBL_Hydroid.xAngle 59.350000 arcdeg
2019-10-30T22:46:24.170Z,1572475584.170 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224623.94*50

2019-10-30T22:46:25.789Z,1572475585.789 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:27.812Z,1572475587.812 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:27.845Z,1572475587.845 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:28.600Z,1572475588.600 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:28.997Z,1572475588.997 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:46:29.467Z,1572475589.467 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:46:29.467Z,1572475589.467 [Reporter](INFO): DUSBL_Hydroid.xAngle 57.650000 arcdeg
2019-10-30T22:46:29.826Z,1572475589.826 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224629.60*51

2019-10-30T22:46:29.841Z,1572475589.841 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:31.857Z,1572475591.857 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:33.479Z,1572475593.479 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:34.252Z,1572475594.252 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:34.665Z,1572475594.665 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:46:35.069Z,1572475595.069 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:35.163Z,1572475595.163 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:46:35.163Z,1572475595.163 [Reporter](INFO): DUSBL_Hydroid.xAngle 59.399997 arcdeg
2019-10-30T22:46:35.482Z,1572475595.482 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224635.25*5D

2019-10-30T22:46:37.303Z,1572475597.303 [CommandLine](IMPORTANT): got command stop
2019-10-30T22:46:37.304Z,1572475597.304 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-30T22:46:37.524Z,1572475597.524 [MissionManager](INFO): MissionManager is completed.
2019-10-30T22:46:37.524Z,1572475597.524 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL] Stopped
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:A.Pitch] Stopped
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:B.SetSpeed] Stopped
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:C.] Stopped
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:RequestRepeater] Stopped
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-10-30T22:46:37.525Z,1572475597.525 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:46:37.899Z,1572475597.899 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:37.935Z,1572475597.935 [MissionManager](IMPORTANT): Started mission Default
2019-10-30T22:46:37.935Z,1572475597.935 [Default] Running Loop=1
2019-10-30T22:46:37.935Z,1572475597.935 [Default](DEBUG): Aggregate::initialize Default
2019-10-30T22:46:37.935Z,1572475597.935 [Default:B.GoToSurface] Running Loop=1
2019-10-30T22:46:37.935Z,1572475597.935 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:46:37.936Z,1572475597.936 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:46:37.936Z,1572475597.936 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:46:37.936Z,1572475597.936 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:46:37.937Z,1572475597.937 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:46:37.937Z,1572475597.937 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:46:37.938Z,1572475597.938 [Default:A.Wait] Running Loop=1
2019-10-30T22:46:37.938Z,1572475597.938 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:46:41.137Z,1572475601.137 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:43.973Z,1572475603.973 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:45.886Z,1572475605.886 [DataOverHttps](IMPORTANT): SBD MTMSN=20191030T224540
2019-10-30T22:46:46.805Z,1572475606.805 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:48.813Z,1572475608.813 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:50.825Z,1572475610.825 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:51.275Z,1572475611.275 [Default:A.Wait](INFO): Done Waiting.
2019-10-30T22:46:51.275Z,1572475611.275 [Default:A.Wait] Stopped
2019-10-30T22:46:51.275Z,1572475611.275 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:46:51.683Z,1572475611.683 [Default:CheckIn] Running Loop=1
2019-10-30T22:46:51.683Z,1572475611.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-30T22:46:51.683Z,1572475611.683 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-30T22:46:53.400Z,1572475613.400 [DataOverHttps](INFO): Received command:load Maintenance/DUSBL_Tracking.xml;set DUSBL.TrackingUpdatePeriod 3 second;run 
2019-10-30T22:46:53.419Z,1572475613.419 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:46:53.420Z,1572475613.420 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:46:53.471Z,1572475613.471 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 10.000000 min
2019-10-30T22:46:53.473Z,1572475613.473 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-10-30T22:46:53.475Z,1572475613.475 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-10-30T22:46:53.477Z,1572475613.477 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-10-30T22:46:53.479Z,1572475613.479 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-10-30T22:46:53.480Z,1572475613.480 [DUSBL:A.Pitch](DEBUG): Construct.
2019-10-30T22:46:53.512Z,1572475613.512 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-10-30T22:46:53.565Z,1572475613.565 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-10-30T22:46:53.573Z,1572475613.573 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

    <Description>
        This mission is requests a DUSBL arming.
    </Description>

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

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>4</Value></DefineArg>
    
    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    
    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>
    
      <Aggregate Id="RequestRepeater">

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

</Mission>


2019-10-30T22:46:53.573Z,1572475613.573 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:46:54.069Z,1572475614.069 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:55.170Z,1572475615.170 [CommandLine](IMPORTANT): got command set DUSBL.TrackingUpdatePeriod 3.000000 second
2019-10-30T22:46:55.171Z,1572475615.171 [CommandLine](IMPORTANT): got command run 
2019-10-30T22:46:55.173Z,1572475615.173 [CommandLine](IMPORTANT): Running 
2019-10-30T22:46:55.308Z,1572475615.308 [Default] Stopped
2019-10-30T22:46:55.308Z,1572475615.308 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-30T22:46:55.308Z,1572475615.308 [Default:B.GoToSurface] Stopped
2019-10-30T22:46:55.308Z,1572475615.308 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-30T22:46:55.309Z,1572475615.309 [Default:CheckIn] Stopped
2019-10-30T22:46:55.309Z,1572475615.309 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-30T22:46:55.309Z,1572475615.309 [Default:CheckIn:Read_GPS] Stopped
2019-10-30T22:46:55.309Z,1572475615.309 [MissionManager](IMPORTANT): Started mission DUSBL
2019-10-30T22:46:55.309Z,1572475615.309 [DUSBL] Running Loop=1
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:C.] Running Loop=1
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:RequestRepeater] Running Loop=1
2019-10-30T22:46:55.310Z,1572475615.310 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-10-30T22:46:55.311Z,1572475615.311 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-10-30T22:46:55.311Z,1572475615.311 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:46:55.311Z,1572475615.311 [DUSBL:C.] Running Loop=1
2019-10-30T22:46:55.311Z,1572475615.311 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:46:55.311Z,1572475615.311 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:46:56.889Z,1572475616.889 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:46:58.523Z,1572475618.523 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:46:59.300Z,1572475619.300 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:46:59.705Z,1572475619.705 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:00.125Z,1572475620.125 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:00.184Z,1572475620.184 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:47:00.185Z,1572475620.185 [Reporter](INFO): DUSBL_Hydroid.xAngle 56.150002 arcdeg
2019-10-30T22:47:00.530Z,1572475620.530 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224700.30*5E

2019-10-30T22:47:02.949Z,1572475622.949 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:03.390Z,1572475623.390 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:04.148Z,1572475624.148 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:04.549Z,1572475624.549 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:05.011Z,1572475625.011 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:47:05.012Z,1572475625.012 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.149997 arcdeg
2019-10-30T22:47:05.378Z,1572475625.378 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224705.15*5C

2019-10-30T22:47:06.197Z,1572475626.197 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:08.215Z,1572475628.215 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:08.996Z,1572475628.996 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:09.014Z,1572475629.014 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:09.397Z,1572475629.397 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:09.884Z,1572475629.884 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:47:09.905Z,1572475629.905 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.750002 arcdeg
2019-10-30T22:47:10.230Z,1572475630.230 [Micromodem](INFO): Nmea in: $SNTTA,0.194663,,,,224710.00*4D

2019-10-30T22:47:11.853Z,1572475631.853 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:13.090Z,1572475633.090 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:13.840Z,1572475633.840 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:14.262Z,1572475634.262 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:14.700Z,1572475634.700 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:47:14.701Z,1572475634.701 [Reporter](INFO): DUSBL_Hydroid.xAngle 60.250000 arcdeg
2019-10-30T22:47:15.086Z,1572475635.086 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224714.84*54

2019-10-30T22:47:15.102Z,1572475635.102 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:17.901Z,1572475637.901 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:17.949Z,1572475637.949 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:18.688Z,1572475638.688 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:19.101Z,1572475639.101 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:19.546Z,1572475639.546 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:47:19.547Z,1572475639.547 [Reporter](INFO): DUSBL_Hydroid.xAngle 57.899999 arcdeg
2019-10-30T22:47:19.920Z,1572475639.920 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224719.70*52

2019-10-30T22:47:21.137Z,1572475641.137 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:22.755Z,1572475642.755 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:23.536Z,1572475643.536 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:23.965Z,1572475643.965 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:23.989Z,1572475643.989 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:24.443Z,1572475644.443 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:47:24.443Z,1572475644.443 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.850003 arcdeg
2019-10-30T22:47:24.774Z,1572475644.774 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224724.54*5A

2019-10-30T22:47:26.817Z,1572475646.817 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:27.644Z,1572475647.644 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:28.384Z,1572475648.384 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:28.797Z,1572475648.797 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:28.845Z,1572475648.845 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:29.270Z,1572475649.270 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:47:29.271Z,1572475649.271 [Reporter](INFO): DUSBL_Hydroid.xAngle 59.650002 arcdeg
2019-10-30T22:47:29.618Z,1572475649.618 [Micromodem](INFO): Nmea in: $SNTTA,0.000115,,,,224729.39*47

2019-10-30T22:47:32.037Z,1572475652.037 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:32.473Z,1572475652.473 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:33.236Z,1572475653.236 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:33.637Z,1572475653.637 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:34.109Z,1572475654.109 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:47:34.110Z,1572475654.110 [Reporter](INFO): DUSBL_Hydroid.xAngle 61.350002 arcdeg
2019-10-30T22:47:34.462Z,1572475654.462 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224734.24*5C

2019-10-30T22:47:34.881Z,1572475654.881 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:37.308Z,1572475657.308 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:47:38.084Z,1572475658.084 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:47:38.101Z,1572475658.101 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:38.485Z,1572475658.485 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:47:38.968Z,1572475658.968 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.780000 m
2019-10-30T22:47:38.968Z,1572475658.968 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.900000 arcdeg
2019-10-30T22:47:39.318Z,1572475659.318 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224739.09*5E

2019-10-30T22:47:39.875Z,1572475659.875 [CommandLine](IMPORTANT): got command stop
2019-10-30T22:47:39.876Z,1572475659.876 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-30T22:47:40.159Z,1572475660.159 [MissionManager](INFO): MissionManager is completed.
2019-10-30T22:47:40.159Z,1572475660.159 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-10-30T22:47:40.159Z,1572475660.159 [DUSBL] Stopped
2019-10-30T22:47:40.159Z,1572475660.159 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-10-30T22:47:40.159Z,1572475660.159 [DUSBL:A.Pitch] Stopped
2019-10-30T22:47:40.160Z,1572475660.160 [DUSBL:B.SetSpeed] Stopped
2019-10-30T22:47:40.160Z,1572475660.160 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-10-30T22:47:40.160Z,1572475660.160 [DUSBL:C.] Stopped
2019-10-30T22:47:40.160Z,1572475660.160 [DUSBL:RequestRepeater] Stopped
2019-10-30T22:47:40.160Z,1572475660.160 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-10-30T22:47:40.160Z,1572475660.160 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-10-30T22:47:40.160Z,1572475660.160 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:47:40.535Z,1572475660.535 [MissionManager](IMPORTANT): Started mission Default
2019-10-30T22:47:40.535Z,1572475660.535 [Default] Running Loop=1
2019-10-30T22:47:40.535Z,1572475660.535 [Default](DEBUG): Aggregate::initialize Default
2019-10-30T22:47:40.535Z,1572475660.535 [Default:B.GoToSurface] Running Loop=1
2019-10-30T22:47:40.535Z,1572475660.535 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:47:40.535Z,1572475660.535 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:47:40.536Z,1572475660.536 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:47:40.536Z,1572475660.536 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:47:40.536Z,1572475660.536 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:47:40.537Z,1572475660.537 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:47:40.538Z,1572475660.538 [Default:A.Wait] Running Loop=1
2019-10-30T22:47:40.538Z,1572475660.538 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:47:40.921Z,1572475660.921 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:44.157Z,1572475664.157 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:46.985Z,1572475666.985 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:49.825Z,1572475669.825 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:51.829Z,1572475671.829 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:53.862Z,1572475673.862 [Default:A.Wait](INFO): Done Waiting.
2019-10-30T22:47:53.863Z,1572475673.863 [Default:A.Wait] Stopped
2019-10-30T22:47:53.863Z,1572475673.863 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:47:54.285Z,1572475674.285 [Default:CheckIn] Running Loop=1
2019-10-30T22:47:54.285Z,1572475674.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-30T22:47:54.286Z,1572475674.286 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-30T22:47:55.061Z,1572475675.061 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:47:57.893Z,1572475677.893 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:01.125Z,1572475681.125 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:03.975Z,1572475683.975 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:06.615Z,1572475686.615 [DataOverHttps](IMPORTANT): SBD MTMSN=20191030T224701
2019-10-30T22:48:07.181Z,1572475687.181 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:08.836Z,1572475688.836 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-10-30T22:48:08.836Z,1572475688.836 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-30T22:48:08.858Z,1572475688.858 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-30T22:48:09.234Z,1572475689.234 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-30T22:48:09.234Z,1572475689.234 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-10-30T22:48:10.013Z,1572475690.013 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:12.865Z,1572475692.865 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:16.040Z,1572475696.040 [DataOverHttps](INFO): Received command:load Maintenance/DUSBL_Tracking.xml;set DUSBL.TrackingUpdatePeriod 2 second;run 
2019-10-30T22:48:16.087Z,1572475696.087 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:48:16.087Z,1572475696.087 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:48:16.105Z,1572475696.105 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:16.207Z,1572475696.207 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 10.000000 min
2019-10-30T22:48:16.221Z,1572475696.221 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-10-30T22:48:16.223Z,1572475696.223 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-10-30T22:48:16.230Z,1572475696.230 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-10-30T22:48:16.232Z,1572475696.232 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-10-30T22:48:16.237Z,1572475696.237 [DUSBL:A.Pitch](DEBUG): Construct.
2019-10-30T22:48:16.246Z,1572475696.246 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-10-30T22:48:16.294Z,1572475696.294 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-10-30T22:48:16.307Z,1572475696.307 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

    <Description>
        This mission is requests a DUSBL arming.
    </Description>

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

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>4</Value></DefineArg>
    
    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    
    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>
    
      <Aggregate Id="RequestRepeater">

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

</Mission>


2019-10-30T22:48:16.308Z,1572475696.308 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:48:17.924Z,1572475697.924 [CommandLine](IMPORTANT): got command set DUSBL.TrackingUpdatePeriod 2.000000 second
2019-10-30T22:48:17.924Z,1572475697.924 [CommandLine](IMPORTANT): got command run 
2019-10-30T22:48:17.926Z,1572475697.926 [CommandLine](IMPORTANT): Running 
2019-10-30T22:48:18.111Z,1572475698.111 [Default] Stopped
2019-10-30T22:48:18.111Z,1572475698.111 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-30T22:48:18.111Z,1572475698.111 [Default:B.GoToSurface] Stopped
2019-10-30T22:48:18.111Z,1572475698.111 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-30T22:48:18.112Z,1572475698.112 [Default:CheckIn] Stopped
2019-10-30T22:48:18.112Z,1572475698.112 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-30T22:48:18.112Z,1572475698.112 [Default:CheckIn:Read_GPS] Stopped
2019-10-30T22:48:18.112Z,1572475698.112 [MissionManager](IMPORTANT): Started mission DUSBL
2019-10-30T22:48:18.112Z,1572475698.112 [DUSBL] Running Loop=1
2019-10-30T22:48:18.112Z,1572475698.112 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-10-30T22:48:18.112Z,1572475698.112 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:48:18.112Z,1572475698.112 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-10-30T22:48:18.125Z,1572475698.125 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:48:18.125Z,1572475698.125 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-10-30T22:48:18.125Z,1572475698.125 [DUSBL:C.] Running Loop=1
2019-10-30T22:48:18.125Z,1572475698.125 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-10-30T22:48:18.125Z,1572475698.125 [DUSBL:RequestRepeater] Running Loop=1
2019-10-30T22:48:18.125Z,1572475698.125 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-10-30T22:48:18.126Z,1572475698.126 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-10-30T22:48:18.126Z,1572475698.126 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:48:18.126Z,1572475698.126 [DUSBL:C.] Running Loop=1
2019-10-30T22:48:18.126Z,1572475698.126 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:48:18.126Z,1572475698.126 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:48:18.910Z,1572475698.910 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:20.143Z,1572475700.143 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:20.908Z,1572475700.908 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:48:21.313Z,1572475701.313 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:48:21.816Z,1572475701.816 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.780000 m
2019-10-30T22:48:21.821Z,1572475701.821 [Reporter](INFO): DUSBL_Hydroid.xAngle 56.199999 arcdeg
2019-10-30T22:48:22.142Z,1572475702.142 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224821.92*5A

2019-10-30T22:48:22.157Z,1572475702.157 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:23.792Z,1572475703.792 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:24.977Z,1572475704.977 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:25.803Z,1572475705.803 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:26.564Z,1572475706.564 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:48:26.985Z,1572475706.985 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:48:27.423Z,1572475707.423 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:48:27.423Z,1572475707.423 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.750002 arcdeg
2019-10-30T22:48:27.802Z,1572475707.802 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224827.57*55

2019-10-30T22:48:27.817Z,1572475707.817 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:29.439Z,1572475709.439 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:29.830Z,1572475709.830 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:31.454Z,1572475711.454 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:31.833Z,1572475711.833 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:32.230Z,1572475712.230 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:48:32.629Z,1572475712.629 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:48:33.105Z,1572475713.105 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:48:33.106Z,1572475713.106 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.050003 arcdeg
2019-10-30T22:48:33.450Z,1572475713.450 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224833.23*53

2019-10-30T22:48:35.073Z,1572475715.073 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:35.124Z,1572475715.124 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:37.506Z,1572475717.506 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:37.893Z,1572475717.893 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:38.290Z,1572475718.290 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:48:38.689Z,1572475718.689 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:48:39.139Z,1572475719.139 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:48:39.139Z,1572475719.139 [Reporter](INFO): DUSBL_Hydroid.xAngle 59.900001 arcdeg
2019-10-30T22:48:39.510Z,1572475719.510 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224839.30*5B

2019-10-30T22:48:41.133Z,1572475721.133 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:41.174Z,1572475721.174 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:43.564Z,1572475723.564 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:43.977Z,1572475723.977 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:44.348Z,1572475724.348 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:48:44.745Z,1572475724.745 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:48:45.238Z,1572475725.238 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.659999 m
2019-10-30T22:48:45.239Z,1572475725.239 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.450000 arcdeg
2019-10-30T22:48:45.570Z,1572475725.570 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224845.35*55

2019-10-30T22:48:46.813Z,1572475726.813 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:47.238Z,1572475727.238 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:48:48.805Z,1572475728.805 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:49.021Z,1572475729.021 [CommandLine](IMPORTANT): got command stop
2019-10-30T22:48:49.021Z,1572475729.021 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-30T22:48:49.231Z,1572475729.231 [MissionManager](INFO): MissionManager is completed.
2019-10-30T22:48:49.231Z,1572475729.231 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-10-30T22:48:49.231Z,1572475729.231 [DUSBL] Stopped
2019-10-30T22:48:49.231Z,1572475729.231 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:A.Pitch] Stopped
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:B.SetSpeed] Stopped
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:C.] Stopped
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:RequestRepeater] Stopped
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-10-30T22:48:49.232Z,1572475729.232 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:48:49.639Z,1572475729.639 [MissionManager](IMPORTANT): Started mission Default
2019-10-30T22:48:49.639Z,1572475729.639 [Default] Running Loop=1
2019-10-30T22:48:49.639Z,1572475729.639 [Default](DEBUG): Aggregate::initialize Default
2019-10-30T22:48:49.639Z,1572475729.639 [Default:B.GoToSurface] Running Loop=1
2019-10-30T22:48:49.639Z,1572475729.639 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:48:49.640Z,1572475729.640 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:48:49.640Z,1572475729.640 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:48:49.640Z,1572475729.640 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:48:49.640Z,1572475729.640 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:48:49.641Z,1572475729.641 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:48:49.641Z,1572475729.641 [Default:A.Wait] Running Loop=1
2019-10-30T22:48:49.641Z,1572475729.641 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:48:50.821Z,1572475730.821 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:51.764Z,1572475731.764 [DataOverHttps](IMPORTANT): SBD MTMSN=20191030T224746
2019-10-30T22:48:52.865Z,1572475732.865 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:56.073Z,1572475736.073 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:58.910Z,1572475738.910 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:48:59.385Z,1572475739.385 [DataOverHttps](INFO): Received command:load Maintenance/DUSBL_Tracking.xml;set DUSBL.TrackingUpdatePeriod 2.5 second;run 
2019-10-30T22:48:59.421Z,1572475739.421 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:48:59.422Z,1572475739.422 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:48:59.442Z,1572475739.442 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 10.000000 min
2019-10-30T22:48:59.444Z,1572475739.444 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-10-30T22:48:59.447Z,1572475739.447 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-10-30T22:48:59.449Z,1572475739.449 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-10-30T22:48:59.451Z,1572475739.451 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-10-30T22:48:59.453Z,1572475739.453 [DUSBL:A.Pitch](DEBUG): Construct.
2019-10-30T22:48:59.457Z,1572475739.457 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-10-30T22:48:59.471Z,1572475739.471 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-10-30T22:48:59.503Z,1572475739.503 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

    <Description>
        This mission is requests a DUSBL arming.
    </Description>

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

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>4</Value></DefineArg>
    
    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    
    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>
    
      <Aggregate Id="RequestRepeater">

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

</Mission>


2019-10-30T22:48:59.503Z,1572475739.503 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/DUSBL_Tracking.xml
2019-10-30T22:49:01.162Z,1572475741.162 [CommandLine](IMPORTANT): got command set DUSBL.TrackingUpdatePeriod 2.500000 second
2019-10-30T22:49:01.162Z,1572475741.162 [CommandLine](IMPORTANT): got command run 
2019-10-30T22:49:01.164Z,1572475741.164 [CommandLine](IMPORTANT): Running 
2019-10-30T22:49:01.354Z,1572475741.354 [Default] Stopped
2019-10-30T22:49:01.354Z,1572475741.354 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-30T22:49:01.354Z,1572475741.354 [Default:A.Wait] Stopped
2019-10-30T22:49:01.354Z,1572475741.354 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:49:01.354Z,1572475741.354 [Default:B.GoToSurface] Stopped
2019-10-30T22:49:01.354Z,1572475741.354 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-30T22:49:01.354Z,1572475741.354 [MissionManager](IMPORTANT): Started mission DUSBL
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL] Running Loop=1
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL:C.] Running Loop=1
2019-10-30T22:49:01.355Z,1572475741.355 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-10-30T22:49:01.356Z,1572475741.356 [DUSBL:RequestRepeater] Running Loop=1
2019-10-30T22:49:01.356Z,1572475741.356 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-10-30T22:49:01.356Z,1572475741.356 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-10-30T22:49:01.356Z,1572475741.356 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-10-30T22:49:01.356Z,1572475741.356 [DUSBL:C.] Running Loop=1
2019-10-30T22:49:01.361Z,1572475741.361 [DUSBL:B.SetSpeed] Running Loop=1
2019-10-30T22:49:01.361Z,1572475741.361 [DUSBL:A.Pitch] Running Loop=1
2019-10-30T22:49:02.129Z,1572475742.129 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:04.212Z,1572475744.212 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:49:04.952Z,1572475744.952 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:49:04.973Z,1572475744.973 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:05.349Z,1572475745.349 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:49:05.810Z,1572475745.810 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:49:05.811Z,1572475745.811 [Reporter](INFO): DUSBL_Hydroid.xAngle 59.399997 arcdeg
2019-10-30T22:49:06.178Z,1572475746.178 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224905.96*59

2019-10-30T22:49:07.817Z,1572475747.817 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:08.638Z,1572475748.638 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:49:09.388Z,1572475749.388 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:49:09.801Z,1572475749.801 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:49:10.213Z,1572475750.213 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:10.265Z,1572475750.265 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.720000 m
2019-10-30T22:49:10.265Z,1572475750.265 [Reporter](INFO): DUSBL_Hydroid.xAngle 60.900002 arcdeg
2019-10-30T22:49:10.618Z,1572475750.618 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224910.39*58

2019-10-30T22:49:13.041Z,1572475753.041 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:13.081Z,1572475753.081 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:49:13.844Z,1572475753.844 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:49:14.245Z,1572475754.245 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:49:14.706Z,1572475754.706 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.599999 m
2019-10-30T22:49:14.706Z,1572475754.706 [Reporter](INFO): DUSBL_Hydroid.xAngle 57.699997 arcdeg
2019-10-30T22:49:15.066Z,1572475755.066 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224914.85*5B

2019-10-30T22:49:15.873Z,1572475755.873 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:17.510Z,1572475757.510 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:49:18.286Z,1572475758.286 [Micromodem](INFO): Nmea out: $CCPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*3E

2019-10-30T22:49:18.681Z,1572475758.681 [Micromodem](INFO): Nmea in: $SNPGT,0,14500,28,6F8F7A90,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,2000,4000,0*23

2019-10-30T22:49:19.097Z,1572475759.097 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:19.179Z,1572475759.179 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 0.539999 m
2019-10-30T22:49:19.180Z,1572475759.180 [Reporter](INFO): DUSBL_Hydroid.xAngle 57.650000 arcdeg
2019-10-30T22:49:19.514Z,1572475759.514 [Micromodem](INFO): Nmea in: $SNTTA,,,,,224919.29*50

2019-10-30T22:49:21.799Z,1572475761.799 [CommandLine](IMPORTANT): got command stop
2019-10-30T22:49:21.800Z,1572475761.800 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-30T22:49:21.929Z,1572475761.929 [NAL9602](DEBUG): Fix Requested
2019-10-30T22:49:21.975Z,1572475761.975 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-10-30T22:49:21.976Z,1572475761.976 [MissionManager](INFO): MissionManager is completed.
2019-10-30T22:49:21.976Z,1572475761.976 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-10-30T22:49:21.976Z,1572475761.976 [DUSBL] Stopped
2019-10-30T22:49:21.976Z,1572475761.976 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-10-30T22:49:21.976Z,1572475761.976 [DUSBL:A.Pitch] Stopped
2019-10-30T22:49:21.977Z,1572475761.977 [DUSBL:B.SetSpeed] Stopped
2019-10-30T22:49:21.981Z,1572475761.981 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-10-30T22:49:21.981Z,1572475761.981 [DUSBL:C.] Stopped
2019-10-30T22:49:21.981Z,1572475761.981 [DUSBL:RequestRepeater] Stopped
2019-10-30T22:49:21.981Z,1572475761.981 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-10-30T22:49:21.981Z,1572475761.981 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-10-30T22:49:21.981Z,1572475761.981 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-30T22:49:22.371Z,1572475762.371 [MissionManager](IMPORTANT): Started mission Default
2019-10-30T22:49:22.371Z,1572475762.371 [Default] Running Loop=1
2019-10-30T22:49:22.371Z,1572475762.371 [Default](DEBUG): Aggregate::initialize Default
2019-10-30T22:49:22.371Z,1572475762.371 [Default:B.GoToSurface] Running Loop=1
2019-10-30T22:49:22.371Z,1572475762.371 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-30T22:49:22.372Z,1572475762.372 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-30T22:49:22.372Z,1572475762.372 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-30T22:49:22.372Z,1572475762.372 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-30T22:49:22.372Z,1572475762.372 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-30T22:49:22.377Z,1572475762.377 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-30T22:49:22.377Z,1572475762.377 [Default:A.Wait] Running Loop=1
2019-10-30T22:49:22.377Z,1572475762.377 [Default:A.Wait](DEBUG): Initialize Wait Component.