2019-07-11T01:04:07.934Z,1562807047.934 [Supervisor](DEBUG): Initializing supervisor.
2019-07-11T01:04:07.937Z,1562807047.937 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-07-11T01:04:07.937Z,1562807047.937 [SyncHandler](INFO): Protected caller Thread ID is 9792
2019-07-11T01:04:07.938Z,1562807047.938 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-07-11T01:04:07.953Z,1562807047.953 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-07-11T01:04:07.953Z,1562807047.953 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9793
2019-07-11T01:04:07.983Z,1562807047.983 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-07-11T01:04:08.029Z,1562807048.029 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-07-11T01:04:08.030Z,1562807048.030 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-07-11T01:04:08.030Z,1562807048.030 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9794
2019-07-11T01:04:08.031Z,1562807048.031 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-07-11T01:04:08.032Z,1562807048.032 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-07-11T01:04:08.032Z,1562807048.032 [logger ThreadHandler](INFO): Protected caller Thread ID is 9795
2019-07-11T01:04:08.034Z,1562807048.034 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-07-11T01:04:08.035Z,1562807048.035 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-07-11T01:04:08.036Z,1562807048.036 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-07-11T01:04:08.963Z,1562807048.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-07-11T01:04:08.964Z,1562807048.964 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-07-11T01:04:09.109Z,1562807049.109 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-07-11T01:04:09.109Z,1562807049.109 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-07-11T01:04:09.418Z,1562807049.418 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-07-11T01:04:09.419Z,1562807049.419 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-07-11T01:04:09.557Z,1562807049.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-07-11T01:04:09.557Z,1562807049.557 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-07-11T01:04:09.745Z,1562807049.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-07-11T01:04:09.746Z,1562807049.746 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-07-11T01:04:10.180Z,1562807050.180 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-07-11T01:04:10.180Z,1562807050.180 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-07-11T01:04:10.382Z,1562807050.382 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-07-11T01:04:10.383Z,1562807050.383 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-07-11T01:04:10.525Z,1562807050.525 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-07-11T01:04:10.525Z,1562807050.525 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-07-11T01:04:10.713Z,1562807050.713 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-07-11T01:04:10.714Z,1562807050.714 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-07-11T01:04:10.809Z,1562807050.809 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-07-11T01:04:10.810Z,1562807050.810 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-07-11T01:04:11.102Z,1562807051.102 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-07-11T01:04:11.102Z,1562807051.102 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-07-11T01:04:11.183Z,1562807051.183 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-07-11T01:04:11.285Z,1562807051.285 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-07-11T01:04:11.285Z,1562807051.285 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-07-11T01:04:11.860Z,1562807051.860 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-07-11T01:04:11.860Z,1562807051.860 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-07-11T01:04:12.241Z,1562807052.241 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-07-11T01:04:12.243Z,1562807052.243 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-07-11T01:04:12.244Z,1562807052.244 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-07-11T01:04:12.447Z,1562807052.447 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-07-11T01:04:12.547Z,1562807052.547 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-07-11T01:04:12.645Z,1562807052.645 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-07-11T01:04:12.868Z,1562807052.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-07-11T01:04:12.869Z,1562807052.869 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-07-11T01:04:12.953Z,1562807052.953 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-07-11T01:04:13.046Z,1562807053.046 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-07-11T01:04:13.142Z,1562807053.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-07-11T01:04:13.226Z,1562807053.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-07-11T01:04:13.332Z,1562807053.332 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-07-11T01:04:13.507Z,1562807053.507 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-07-11T01:04:13.635Z,1562807053.635 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-07-11T01:04:13.635Z,1562807053.635 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-07-11T01:04:13.637Z,1562807053.637 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-07-11T01:04:14.029Z,1562807054.029 [AHRS_M2] Loaded
2019-07-11T01:04:14.030Z,1562807054.030 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-07-11T01:04:14.110Z,1562807054.110 [DataOverHttps] Loaded
2019-07-11T01:04:14.110Z,1562807054.110 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-07-11T01:04:14.111Z,1562807054.111 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407654E0
2019-07-11T01:04:14.111Z,1562807054.111 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9874
2019-07-11T01:04:14.124Z,1562807054.124 [Depth_Keller] Loaded
2019-07-11T01:04:14.124Z,1562807054.124 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-07-11T01:04:14.129Z,1562807054.129 [DropWeight] Loaded
2019-07-11T01:04:14.129Z,1562807054.129 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-07-11T01:04:14.184Z,1562807054.184 [DUSBL_Hydroid] Loaded
2019-07-11T01:04:14.185Z,1562807054.185 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-07-11T01:04:14.233Z,1562807054.233 [Micromodem] Loaded
2019-07-11T01:04:14.233Z,1562807054.233 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-07-11T01:04:14.328Z,1562807054.328 [NAL9602] Loaded
2019-07-11T01:04:14.328Z,1562807054.328 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-07-11T01:04:14.344Z,1562807054.344 [Onboard] Loaded
2019-07-11T01:04:14.344Z,1562807054.344 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-07-11T01:04:14.350Z,1562807054.350 [PowerOnly] Loaded
2019-07-11T01:04:14.350Z,1562807054.350 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-07-11T01:04:14.356Z,1562807054.356 [Radio_Surface] Loaded
2019-07-11T01:04:14.357Z,1562807054.357 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-07-11T01:04:14.358Z,1562807054.358 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407954E0
2019-07-11T01:04:14.358Z,1562807054.358 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9875
2019-07-11T01:04:14.401Z,1562807054.401 [RDI_Pathfinder] Loaded
2019-07-11T01:04:14.401Z,1562807054.401 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-07-11T01:04:16.426Z,1562807056.426 [BPC1] Loaded
2019-07-11T01:04:16.426Z,1562807056.426 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-07-11T01:04:16.427Z,1562807056.427 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-07-11T01:04:16.427Z,1562807056.427 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-07-11T01:04:16.440Z,1562807056.440 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-07-11T01:04:16.441Z,1562807056.441 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-07-11T01:04:16.544Z,1562807056.544 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-07-11T01:04:16.544Z,1562807056.544 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-07-11T01:04:16.565Z,1562807056.565 [NavChart] Loaded
2019-07-11T01:04:16.565Z,1562807056.565 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-07-11T01:04:16.569Z,1562807056.569 [UniversalFixResidualReporter] Loaded
2019-07-11T01:04:16.569Z,1562807056.569 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-07-11T01:04:16.569Z,1562807056.569 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-07-11T01:04:16.570Z,1562807056.570 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-07-11T01:04:16.671Z,1562807056.671 [BuoyancyServo] Loaded
2019-07-11T01:04:16.672Z,1562807056.672 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-07-11T01:04:16.686Z,1562807056.686 [ElevatorServo] Loaded
2019-07-11T01:04:16.687Z,1562807056.687 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-07-11T01:04:16.701Z,1562807056.701 [MassServo] Loaded
2019-07-11T01:04:16.701Z,1562807056.701 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-07-11T01:04:16.716Z,1562807056.716 [RudderServo] Loaded
2019-07-11T01:04:16.716Z,1562807056.716 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-07-11T01:04:16.731Z,1562807056.731 [ThrusterServo] Loaded
2019-07-11T01:04:16.731Z,1562807056.731 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-07-11T01:04:16.731Z,1562807056.731 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-07-11T01:04:16.732Z,1562807056.732 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-07-11T01:04:16.969Z,1562807056.969 [CTD_NeilBrown] Loaded
2019-07-11T01:04:16.970Z,1562807056.970 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-07-11T01:04:16.971Z,1562807056.971 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E04E0
2019-07-11T01:04:16.971Z,1562807056.971 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 9876
2019-07-11T01:04:17.014Z,1562807057.014 [WetLabsSeaOWL_UV_A] Loaded
2019-07-11T01:04:17.015Z,1562807057.015 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-07-11T01:04:17.016Z,1562807057.016 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409104E0
2019-07-11T01:04:17.016Z,1562807057.016 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 9877
2019-07-11T01:04:17.017Z,1562807057.017 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-07-11T01:04:17.017Z,1562807057.017 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-07-11T01:04:17.293Z,1562807057.293 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-07-11T01:04:17.293Z,1562807057.293 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-07-11T01:04:17.333Z,1562807057.333 [DepthRateCalculator] Loaded
2019-07-11T01:04:17.333Z,1562807057.333 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-07-11T01:04:17.339Z,1562807057.339 [PitchRateCalculator] Loaded
2019-07-11T01:04:17.339Z,1562807057.339 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-07-11T01:04:17.351Z,1562807057.351 [SpeedCalculator] Loaded
2019-07-11T01:04:17.351Z,1562807057.351 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-07-11T01:04:17.371Z,1562807057.371 [TempGradientCalculator] Loaded
2019-07-11T01:04:17.372Z,1562807057.372 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-07-11T01:04:17.377Z,1562807057.377 [YawRateCalculator] Loaded
2019-07-11T01:04:17.377Z,1562807057.377 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-07-11T01:04:17.418Z,1562807057.418 [ElevatorOffsetCalculator] Loaded
2019-07-11T01:04:17.418Z,1562807057.418 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-07-11T01:04:17.418Z,1562807057.418 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-07-11T01:04:17.419Z,1562807057.419 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-07-11T01:04:17.547Z,1562807057.547 [SBIT](DEBUG): Construct Startup Built In Test.
2019-07-11T01:04:17.568Z,1562807057.568 [SBIT] Loaded
2019-07-11T01:04:17.568Z,1562807057.568 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-07-11T01:04:17.569Z,1562807057.569 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-07-11T01:04:17.580Z,1562807057.580 [IBIT] Loaded
2019-07-11T01:04:17.580Z,1562807057.580 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-07-11T01:04:17.583Z,1562807057.583 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-07-11T01:04:17.722Z,1562807057.722 [CBIT] Loaded
2019-07-11T01:04:17.722Z,1562807057.722 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-07-11T01:04:17.722Z,1562807057.722 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-07-11T01:04:17.723Z,1562807057.723 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-07-11T01:04:17.799Z,1562807057.799 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-07-11T01:04:17.799Z,1562807057.799 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-07-11T01:04:17.891Z,1562807057.891 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-07-11T01:04:17.891Z,1562807057.891 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-07-11T01:04:17.955Z,1562807057.955 [VerticalControl](DEBUG): Construct VerticalControl.
2019-07-11T01:04:18.037Z,1562807058.037 [VerticalControl] Loaded
2019-07-11T01:04:18.038Z,1562807058.038 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-07-11T01:04:18.039Z,1562807058.039 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-07-11T01:04:18.094Z,1562807058.094 [HorizontalControl] Loaded
2019-07-11T01:04:18.094Z,1562807058.094 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-07-11T01:04:18.095Z,1562807058.095 [SpeedControl](DEBUG): Construct SpeedControl.
2019-07-11T01:04:18.096Z,1562807058.096 [SpeedControl] Loaded
2019-07-11T01:04:18.097Z,1562807058.097 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-07-11T01:04:18.097Z,1562807058.097 [LoopControl](DEBUG): Construct LoopControl.
2019-07-11T01:04:18.098Z,1562807058.098 [LoopControl] Loaded
2019-07-11T01:04:18.098Z,1562807058.098 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-07-11T01:04:18.098Z,1562807058.098 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-07-11T01:04:18.099Z,1562807058.099 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-07-11T01:04:18.129Z,1562807058.129 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-07-11T01:04:18.133Z,1562807058.133 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-07-11T01:04:18.134Z,1562807058.134 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-07-11T01:04:18.140Z,1562807058.140 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-07-11T01:04:18.141Z,1562807058.141 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2019-07-11T01:04:18.142Z,1562807058.142 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9878
2019-07-11T01:04:18.146Z,1562807058.146 [Supervisor](INFO): Main Thread ID is 9651
2019-07-11T01:04:18.146Z,1562807058.146 [Supervisor](DEBUG): Running supervisor.
2019-07-11T01:04:18.147Z,1562807058.147 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9879
2019-07-11T01:04:18.149Z,1562807058.149 [controlThread ThreadHandler](INFO): Handler Thread ID is 9880
2019-07-11T01:04:18.149Z,1562807058.149 [controlThread](DEBUG): Initializing ControlThread
2019-07-11T01:04:18.158Z,1562807058.158 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-07-11T01:04:18.158Z,1562807058.158 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-07-11T01:04:18.159Z,1562807058.159 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-07-11T01:04:18.159Z,1562807058.159 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-07-11T01:04:18.160Z,1562807058.160 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-07-11T01:04:18.160Z,1562807058.160 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-07-11T01:04:18.161Z,1562807058.161 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-07-11T01:04:18.161Z,1562807058.161 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-07-11T01:04:18.161Z,1562807058.161 [SBIT](INFO): Initialize SBIT Component.
2019-07-11T01:04:18.162Z,1562807058.162 [SBIT](IMPORTANT): git: 2019-07-01-2-g8df750c
2019-07-11T01:04:18.162Z,1562807058.162 [SBIT](INFO): git hash: 8df750cfd7ab665d8785a0cb54650bf6fbbccb32
2019-07-11T01:04:18.163Z,1562807058.163 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-07-11T01:04:18.164Z,1562807058.164 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-07-11T01:04:18.165Z,1562807058.165 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-07-11T01:04:18.165Z,1562807058.165 [IBIT](INFO): Initialize IBIT Component.
2019-07-11T01:04:18.166Z,1562807058.166 [CBIT](DEBUG): Initialize CBIT Component.
2019-07-11T01:04:18.167Z,1562807058.167 [logger ThreadHandler](INFO): Handler Thread ID is 9881
2019-07-11T01:04:18.179Z,1562807058.179 [CBIT](DEBUG): Initialized mux pins.
2019-07-11T01:04:18.179Z,1562807058.179 [CBIT](DEBUG): Initializing the watchdog timer.
2019-07-11T01:04:18.187Z,1562807058.187 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9882
2019-07-11T01:04:18.188Z,1562807058.188 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-07-11T01:04:18.199Z,1562807058.199 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9883
2019-07-11T01:04:18.202Z,1562807058.202 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-07-11T01:04:18.202Z,1562807058.202 [CBIT](DEBUG): Initializing heartbeat.
2019-07-11T01:04:18.211Z,1562807058.211 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 9884
2019-07-11T01:04:18.212Z,1562807058.212 [CTD_NeilBrown](INFO): Powering down
2019-07-11T01:04:18.247Z,1562807058.247 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 9885
2019-07-11T01:04:18.247Z,1562807058.247 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-07-11T01:04:18.269Z,1562807058.269 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9886
2019-07-11T01:04:18.272Z,1562807058.272 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-07-11T01:04:18.273Z,1562807058.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-07-11T01:04:18.273Z,1562807058.273 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-07-11T01:04:18.273Z,1562807058.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-07-11T01:04:18.273Z,1562807058.273 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-07-11T01:04:18.273Z,1562807058.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-07-11T01:04:18.273Z,1562807058.273 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-07-11T01:04:18.274Z,1562807058.274 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-07-11T01:04:18.274Z,1562807058.274 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-07-11T01:04:18.274Z,1562807058.274 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-07-11T01:04:18.274Z,1562807058.274 [CBIT](DEBUG): Deactivating GF circuits.
2019-07-11T01:04:18.274Z,1562807058.274 [CBIT](DEBUG): Deactivating emergency mode.
2019-07-11T01:04:18.275Z,1562807058.275 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-07-11T01:04:18.275Z,1562807058.275 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-07-11T01:04:18.275Z,1562807058.275 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-07-11T01:04:18.275Z,1562807058.275 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-07-11T01:04:18.275Z,1562807058.275 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-07-11T01:04:18.276Z,1562807058.276 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-07-11T01:04:18.310Z,1562807058.310 [CBIT](DEBUG): Backplane powered.
2019-07-11T01:04:18.311Z,1562807058.311 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-07-11T01:04:18.312Z,1562807058.312 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-07-11T01:04:18.313Z,1562807058.313 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-07-11T01:04:18.313Z,1562807058.313 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-07-11T01:04:18.314Z,1562807058.314 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-07-11T01:04:18.325Z,1562807058.325 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-11T01:04:18.343Z,1562807058.343 [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-07-11T01:04:18.344Z,1562807058.344 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-07-11T01:04:18.418Z,1562807058.418 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-07-11T01:04:18.420Z,1562807058.420 [Default:A.Wait](DEBUG): Construct Wait.
2019-07-11T01:04:18.421Z,1562807058.421 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-11T01:04:18.464Z,1562807058.464 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-07-11T01:04:18.490Z,1562807058.490 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-07-11T01:04:18.496Z,1562807058.496 [Default:E.Execute](DEBUG): Construct Execute.
2019-07-11T01:04:18.507Z,1562807058.507 [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-07-11T01:04:18.519Z,1562807058.519 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,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-07-11T01:04:18.554Z,1562807058.554 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-07-11T01:04:18.602Z,1562807058.602 [Radio_Surface](INFO): Powering up
2019-07-11T01:04:18.611Z,1562807058.611 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-07-11T01:04:18.612Z,1562807058.612 [DUSBL_Hydroid](INFO): Powering up
2019-07-11T01:04:18.612Z,1562807058.612 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-07-11T01:04:18.687Z,1562807058.687 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-07-11T01:04:18.706Z,1562807058.706 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-07-11T01:04:18.718Z,1562807058.718 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-07-11T01:04:18.719Z,1562807058.719 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-07-11T01:04:18.727Z,1562807058.727 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-07-11T01:04:18.728Z,1562807058.728 [MassServo](DEBUG): Initializing EZServoServo.
2019-07-11T01:04:18.735Z,1562807058.735 [MassServo](DEBUG): Initializing MassServo.
2019-07-11T01:04:18.735Z,1562807058.735 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-11T01:04:18.743Z,1562807058.743 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-11T01:04:18.743Z,1562807058.743 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-07-11T01:04:18.751Z,1562807058.751 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-07-11T01:04:19.036Z,1562807059.036 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-07-11T01:04:19.036Z,1562807059.036 [DropWeight] Hardware Fault, FailCount= 1
2019-07-11T01:04:19.036Z,1562807059.036 [DropWeight](ERROR): Hardware Fault
2019-07-11T01:04:19.038Z,1562807059.038 [Micromodem](INFO): Powering up
2019-07-11T01:04:19.038Z,1562807059.038 [Micromodem](DEBUG): Initializing Micromodem.
2019-07-11T01:04:19.090Z,1562807059.090 [CommandLine](FAULT): Scheduling is paused
2019-07-11T01:04:19.090Z,1562807059.090 [CBIT](INFO): Critical error at 20190711T010419
2019-07-11T01:04:19.090Z,1562807059.090 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-07-11T01:04:19.093Z,1562807059.093 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-07-11T01:04:19.093Z,1562807059.093 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-07-11T01:04:19.690Z,1562807059.690 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-07-11T01:04:19.691Z,1562807059.691 [RudderServo](FAULT): Rudder failed to initialize
2019-07-11T01:04:19.691Z,1562807059.691 [RudderServo] Communications Fault, FailCount= 1
2019-07-11T01:04:19.691Z,1562807059.691 [RudderServo](ERROR): Communications Fault
2019-07-11T01:04:19.800Z,1562807059.800 [CBIT](INFO): Critical error at 20190711T010419
2019-07-11T01:04:19.803Z,1562807059.803 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-07-11T01:04:19.967Z,1562807059.967 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-11T01:04:19.967Z,1562807059.967 [RudderServo](INFO): Powering down
2019-07-11T01:04:20.646Z,1562807060.646 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-11T01:04:20.767Z,1562807060.767 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-11T01:04:20.771Z,1562807060.771 [CBIT](INFO): Clearing failed state for component RudderServo
2019-07-11T01:04:20.771Z,1562807060.771 [RudderServo] No Fault, FailCount= 1
2019-07-11T01:04:23.889Z,1562807063.889 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-07-11T01:04:25.925Z,1562807065.925 [Micromodem](INFO): Nmea in: $CATMG,2019-07-11T01:04:24Z,RTC,RTC*70

2019-07-11T01:04:25.925Z,1562807065.925 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-07-11T01:04:24Z,RTC,RTC*70

2019-07-11T01:04:31.978Z,1562807071.978 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-07-11T01:04:35.181Z,1562807075.181 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-07-11T01:04:35.585Z,1562807075.585 [Micromodem](INFO): Nmea in: $CAERR,010435,NI  ,12,Unknown command*4F

2019-07-11T01:04:35.586Z,1562807075.586 [Micromodem](ERROR): Got error from modem: $CAERR,010435,NI  ,12,Unknown command*4F

2019-07-11T01:04:36.807Z,1562807076.807 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-07-11T01:04:42.064Z,1562807082.064 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2019-07-11T01:04:42.065Z,1562807082.065 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,  +2,A
2019-07-11T01:04:44.470Z,1562807084.470 [NAL9602](INFO): Powering up NAL9602
2019-07-11T01:04:46.488Z,1562807086.488 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-07-11T01:04:46.893Z,1562807086.893 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-07-11T01:04:46.893Z,1562807086.893 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-07-11T01:04:46.989Z,1562807086.989 [SBIT](IMPORTANT): Beginning Startup BIT
2019-07-11T01:04:46.993Z,1562807086.993 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-11T01:04:47.297Z,1562807087.297 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-07-11T01:04:47.297Z,1562807087.297 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-07-11T01:04:47.708Z,1562807087.708 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-07-11T01:04:47.709Z,1562807087.709 [Micromodem](INFO): Nmea out: $CCCFG,nav.nst,1*4D

2019-07-11T01:04:48.109Z,1562807088.109 [Micromodem](INFO): Nmea in: $CACFG,nav.nst,1*4F

2019-07-11T01:04:48.109Z,1562807088.109 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2019-07-11T01:04:48.509Z,1562807088.509 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2019-07-11T01:04:48.509Z,1562807088.509 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2019-07-11T01:04:48.913Z,1562807088.913 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2019-07-11T01:04:48.913Z,1562807088.913 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2019-07-11T01:04:49.325Z,1562807089.325 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2019-07-11T01:04:49.325Z,1562807089.325 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2019-07-11T01:04:49.984Z,1562807089.984 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2019-07-11T01:04:49.984Z,1562807089.984 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2019-07-11T01:04:50.372Z,1562807090.372 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2019-07-11T01:04:50.373Z,1562807090.373 [Micromodem](INFO): Nmea out: $CCCLK,2019,07,11,01,04,51*48

2019-07-11T01:04:50.776Z,1562807090.776 [Micromodem](INFO): Nmea in: $CACLK,2019,7,11,1,4,51*7A

2019-07-11T01:04:51.584Z,1562807091.584 [Micromodem](INFO): Nmea in: $CATMS,0,2019-07-11T01:04:52Z*79

2019-07-11T01:04:51.617Z,1562807091.617 [Micromodem](INFO): Nmea in: $CATMG,2019-07-11T01:04:52Z,USER_CMD,RTC*30

2019-07-11T01:04:55.624Z,1562807095.624 [NAL9602](INFO): NAL9602 initialized
2019-07-11T01:04:56.446Z,1562807096.446 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:04:58.139Z,1562807098.139 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.022660
CHAN A1 (24V): -0.026878
CHAN A2 (12V): -0.006621
CHAN A3 (5V): -0.002104
CHAN B0 (3.3V): 0.000125
CHAN B1 (3.15aV): 0.000201
CHAN B2 (3.15bV): 0.000287
CHAN B3 (GND): 0.001898
OPEN: 0.006966
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-11T01:05:16.310Z,1562807116.310 [NAL9602](INFO): SBD MO Status=0, MOMSN=8110, MT Status=0, MTMSN=0
2019-07-11T01:05:16.310Z,1562807116.310 [NAL9602](INFO): No messages in MT queue
2019-07-11T01:05:17.138Z,1562807117.138 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:19.146Z,1562807119.146 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:21.166Z,1562807121.166 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:24.402Z,1562807124.402 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:27.230Z,1562807127.230 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:30.530Z,1562807130.530 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:33.358Z,1562807133.358 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:36.190Z,1562807136.190 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:38.611Z,1562807138.611 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:41.091Z,1562807141.091 [SBIT](IMPORTANT): SBIT PASSED
2019-07-11T01:05:41.139Z,1562807141.139 [CommandLine](IMPORTANT): got command configSet list
2019-07-11T01:05:41.140Z,1562807141.140 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-11T01:05:41.140Z,1562807141.140 [CommandLine](IMPORTANT): No configSet variables persisted
2019-07-11T01:05:41.438Z,1562807141.438 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:41.467Z,1562807141.467 [MissionManager](IMPORTANT): Started mission Startup
2019-07-11T01:05:41.468Z,1562807141.468 [Startup] Running Loop=1
2019-07-11T01:05:41.468Z,1562807141.468 [Startup](DEBUG): Aggregate::initialize Startup
2019-07-11T01:05:41.468Z,1562807141.468 [Startup:A.GoToSurface] Running Loop=1
2019-07-11T01:05:41.468Z,1562807141.468 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:05:41.469Z,1562807141.469 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:05:41.469Z,1562807141.469 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:05:41.469Z,1562807141.469 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:05:41.470Z,1562807141.470 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:05:41.490Z,1562807141.490 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:05:41.492Z,1562807141.492 [Startup:StartupSatComms] Running Loop=1
2019-07-11T01:05:41.492Z,1562807141.492 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-07-11T01:05:41.492Z,1562807141.492 [Startup:StartupSatComms:A] Running Loop=1
2019-07-11T01:05:41.883Z,1562807141.883 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-07-11T01:05:44.674Z,1562807144.674 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:47.498Z,1562807147.498 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:50.322Z,1562807150.322 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:53.554Z,1562807153.554 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:54.353Z,1562807154.353 [Micromodem](INFO): Nmea in: 42$CAREV,010554,AUV,2.0.27690*10

2019-07-11T01:05:56.385Z,1562807156.385 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:05:59.214Z,1562807159.214 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:02.045Z,1562807162.045 [RDI_Pathfinder](ERROR): Failed to parse:,    -2,   +23,    +3,A
2019-07-11T01:06:02.450Z,1562807162.450 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:05.274Z,1562807165.274 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:08.506Z,1562807168.506 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:11.330Z,1562807171.330 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:14.578Z,1562807174.578 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:17.394Z,1562807177.394 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:20.622Z,1562807180.622 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:06:21.014Z,1562807181.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010506.00,A,3648.15719,N,12147.28461,W,0.272,0.00,110719,,,A*7C
2019-07-11T01:06:21.018Z,1562807181.018 [NAL9602](INFO): GPS fix at 20190711T010506: (36.802620, -121.788077)
2019-07-11T01:06:21.052Z,1562807181.052 [Startup:StartupSatComms:A] Stopped
2019-07-11T01:06:21.052Z,1562807181.052 [Startup:StartupSatComms:B] Running Loop=1
2019-07-11T01:06:21.469Z,1562807181.469 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-11T01:06:22.652Z,1562807182.652 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 078B265D000001005D00000400630200000000000000151D80030C5669BF31555EAE1409A708CE2489B0D24F922C4E73F3619C1A3D5DFEC97D4617D39DECC9F9
2019-07-11T01:06:22.652Z,1562807182.652 [Micromodem](INFO): Outgoing frame #2, 64 bytes: D51B07A2545A898E234697DBACDA3A8E45910E0FC5499E3D6FBF3A2831E49318D470B0BB781FC0AE7746315932CB9824637A3EABD5B1605D4775D9B246C4CE48
2019-07-11T01:06:22.653Z,1562807182.653 [Micromodem](INFO): Outgoing frame #3, 64 bytes: 6319490D9AD9F43E82552BF79F91200102B364EFE383D4865D739D2D806C5084CE5F914BAA55F3A5E84B1886E142FBD6444509716DB95B667913BD821B21E34A
2019-07-11T01:06:22.653Z,1562807182.653 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53

2019-07-11T01:06:22.798Z,1562807182.798 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51

2019-07-11T01:06:23.134Z,1562807183.134 [Micromodem](INFO): Nmea in: $CADRQ,010623,1,9,0,64,1*48

2019-07-11T01:06:23.135Z,1562807183.135 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,078B265D000001005D00000400630200000000000000151D80030C5669BF31555EAE1409A708CE2489B0D24F922C4E73F3619C1A3D5DFEC97D4617D39DECC9F9*0E

2019-07-11T01:06:23.540Z,1562807183.540 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71

2019-07-11T01:06:23.944Z,1562807183.944 [Micromodem](INFO): Nmea in: $CADRQ,010623,1,9,0,64,2*4B

2019-07-11T01:06:23.944Z,1562807183.944 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,D51B07A2545A898E234697DBACDA3A8E45910E0FC5499E3D6FBF3A2831E49318D470B0BB781FC0AE7746315932CB9824637A3EABD5B1605D4775D9B246C4CE48*0A

2019-07-11T01:06:24.348Z,1562807184.348 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71

2019-07-11T01:06:24.752Z,1562807184.752 [Micromodem](INFO): Nmea in: $CADRQ,010624,1,9,0,64,3*4D

2019-07-11T01:06:24.752Z,1562807184.752 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,6319490D9AD9F43E82552BF79F91200102B364EFE383D4865D739D2D806C5084CE5F914BAA55F3A5E84B1886E142FBD6444509716DB95B667913BD821B21E34A*01

2019-07-11T01:06:25.168Z,1562807185.168 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71

2019-07-11T01:06:25.560Z,1562807185.560 [Micromodem](INFO): Nmea in: $CATXP,192*48

2019-07-11T01:06:33.236Z,1562807193.236 [Micromodem](INFO): Nmea in: $CATXF,192*5E

2019-07-11T01:06:34.453Z,1562807194.453 [Micromodem](INFO): Nmea in: $CAXST,6,20190711,010625.575509,3,0,200,2000,14500,1,1,9,1,3,3,3,192*41

2019-07-11T01:06:45.984Z,1562807205.984 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004618
2019-07-11T01:06:52.446Z,1562807212.446 [DataOverHttps](INFO): Sending 304 bytes from file Logs/20190711T010407/Courier0000.lzma
2019-07-11T01:06:53.042Z,1562807213.042 [NAL9602](INFO): Powering down
2019-07-11T01:06:53.252Z,1562807213.252 [DataOverHttps](INFO): Moved sent file to Logs/20190711T010407/Courier0000.lzma.bak
2019-07-11T01:06:53.252Z,1562807213.252 [DataOverHttps](INFO): SBD MOMSN=11438608
2019-07-11T01:07:06.746Z,1562807226.746 [DataOverHttps](INFO): Sending 100 bytes from file Logs/20190711T005748/Express0008.lzma
2019-07-11T01:07:07.552Z,1562807227.552 [DataOverHttps](INFO): Moved sent file to Logs/20190711T005748/Express0008.lzma.bak
2019-07-11T01:07:07.552Z,1562807227.552 [DataOverHttps](INFO): SBD MOMSN=11438614
2019-07-11T01:07:21.342Z,1562807241.342 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-11T01:06:21.1Z
2019-07-11T01:07:21.342Z,1562807241.342 [Startup:StartupSatComms:B] Stopped
2019-07-11T01:07:21.342Z,1562807241.342 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-07-11T01:07:21.346Z,1562807241.346 [Startup:StartupSatComms] Stopped
2019-07-11T01:07:21.346Z,1562807241.346 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-07-11T01:07:21.347Z,1562807241.347 [Startup](INFO): Completed Startup
2019-07-11T01:07:21.347Z,1562807241.347 [MissionManager](INFO): Startup is completed.
2019-07-11T01:07:21.347Z,1562807241.347 [MissionManager](INFO): Uninitializing Mission Startup
2019-07-11T01:07:21.348Z,1562807241.348 [Startup] Stopped
2019-07-11T01:07:21.348Z,1562807241.348 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-07-11T01:07:21.348Z,1562807241.348 [Startup:A.GoToSurface] Stopped
2019-07-11T01:07:21.348Z,1562807241.348 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-11T01:07:21.745Z,1562807241.745 [MissionManager](IMPORTANT): Started mission Default
2019-07-11T01:07:21.746Z,1562807241.746 [Default] Running Loop=1
2019-07-11T01:07:21.746Z,1562807241.746 [Default](DEBUG): Aggregate::initialize Default
2019-07-11T01:07:21.746Z,1562807241.746 [Default:B.GoToSurface] Running Loop=1
2019-07-11T01:07:21.746Z,1562807241.746 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:07:21.750Z,1562807241.750 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:07:21.751Z,1562807241.751 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:07:21.751Z,1562807241.751 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:07:21.751Z,1562807241.751 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:07:21.752Z,1562807241.752 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:07:21.752Z,1562807241.752 [Default:A.Wait] Running Loop=1
2019-07-11T01:07:21.752Z,1562807241.752 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:07:22.455Z,1562807242.455 [DataOverHttps](INFO): Sending 733 bytes from file Logs/20190711T010407/Express0001.lzma
2019-07-11T01:07:23.260Z,1562807243.260 [DataOverHttps](INFO): Moved sent file to Logs/20190711T010407/Express0001.lzma.bak
2019-07-11T01:07:23.260Z,1562807243.260 [DataOverHttps](INFO): SBD MOMSN=11438617
2019-07-11T01:07:35.100Z,1562807255.100 [Default:A.Wait](INFO): Done Waiting.
2019-07-11T01:07:35.101Z,1562807255.101 [Default:A.Wait] Stopped
2019-07-11T01:07:35.101Z,1562807255.101 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:07:35.502Z,1562807255.502 [Default:CheckIn] Running Loop=1
2019-07-11T01:07:35.502Z,1562807255.502 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-11T01:07:35.506Z,1562807255.506 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-11T01:07:35.910Z,1562807255.910 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-07-11T01:07:36.260Z,1562807256.260 [NAL9602](INFO): Powering up
2019-07-11T01:07:47.170Z,1562807267.170 [NAL9602](INFO): NAL9602 initialized
2019-07-11T01:07:47.994Z,1562807267.994 [NAL9602](DEBUG): Fix Requested
2019-07-11T01:07:49.655Z,1562807269.655 [CommandLine](INFO): End of History
2019-07-11T01:07:59.451Z,1562807279.451 [CommandLine](IMPORTANT): got command run ./Missions/DUSBL_Tracking.xml
2019-07-11T01:07:59.451Z,1562807279.451 [MissionManager](INFO): Loading Mission: ./Missions/DUSBL_Tracking.xml
2019-07-11T01:07:59.501Z,1562807279.501 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 5.000000 min
2019-07-11T01:07:59.505Z,1562807279.505 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-07-11T01:07:59.516Z,1562807279.516 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-07-11T01:07:59.535Z,1562807279.535 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-07-11T01:07:59.543Z,1562807279.543 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-07-11T01:07:59.544Z,1562807279.544 [DUSBL:A.Pitch](DEBUG): Construct.
2019-07-11T01:07:59.571Z,1562807279.571 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-07-11T01:07:59.861Z,1562807279.861 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-07-11T01:07:59.877Z,1562807279.877 [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>5</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-07-11T01:07:59.891Z,1562807279.891 [CommandLine](IMPORTANT): Running ./Missions/DUSBL_Tracking.xml
2019-07-11T01:08:00.094Z,1562807280.094 [Default] Stopped
2019-07-11T01:08:00.094Z,1562807280.094 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-11T01:08:00.094Z,1562807280.094 [Default:B.GoToSurface] Stopped
2019-07-11T01:08:00.102Z,1562807280.102 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-11T01:08:00.102Z,1562807280.102 [Default:CheckIn] Stopped
2019-07-11T01:08:00.102Z,1562807280.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-11T01:08:00.103Z,1562807280.103 [Default:CheckIn:Read_GPS] Stopped
2019-07-11T01:08:00.103Z,1562807280.103 [MissionManager](IMPORTANT): Started mission DUSBL
2019-07-11T01:08:00.103Z,1562807280.103 [DUSBL] Running Loop=1
2019-07-11T01:08:00.103Z,1562807280.103 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-07-11T01:08:00.103Z,1562807280.103 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:08:00.103Z,1562807280.103 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-07-11T01:08:00.103Z,1562807280.103 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:08:00.104Z,1562807280.104 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-07-11T01:08:00.104Z,1562807280.104 [DUSBL:C.] Running Loop=1
2019-07-11T01:08:00.104Z,1562807280.104 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-07-11T01:08:00.104Z,1562807280.104 [DUSBL:RequestRepeater] Running Loop=1
2019-07-11T01:08:00.104Z,1562807280.104 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-07-11T01:08:00.104Z,1562807280.104 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-07-11T01:08:00.104Z,1562807280.104 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:08:00.105Z,1562807280.105 [DUSBL:C.] Running Loop=1
2019-07-11T01:08:00.105Z,1562807280.105 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:08:00.106Z,1562807280.106 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:08:03.052Z,1562807283.052 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-07-11T01:08:03.053Z,1562807283.053 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,    -7,   +8,A
2019-07-11T01:08:04.284Z,1562807284.284 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:05.041Z,1562807285.041 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:05.445Z,1562807285.445 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:09.930Z,1562807289.930 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:10.696Z,1562807290.696 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:11.101Z,1562807291.101 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:15.568Z,1562807295.568 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:16.349Z,1562807296.349 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:16.757Z,1562807296.757 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:17.203Z,1562807297.203 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-11T01:08:17.203Z,1562807297.203 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19071018171006,.1,   0.0,1448.9,  0
2019-07-11T01:08:21.263Z,1562807301.263 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:22.009Z,1562807302.009 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:22.413Z,1562807302.413 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:25.251Z,1562807305.251 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:08:25.276Z,1562807305.276 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:26.050Z,1562807306.050 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:26.449Z,1562807306.449 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:30.963Z,1562807310.963 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:31.698Z,1562807311.698 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:32.109Z,1562807312.109 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:34.931Z,1562807314.931 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:08:34.996Z,1562807314.996 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:35.741Z,1562807315.741 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:36.149Z,1562807316.149 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:38.972Z,1562807318.972 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:08:39.040Z,1562807319.040 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:39.783Z,1562807319.783 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:40.189Z,1562807320.189 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:43.011Z,1562807323.011 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:08:43.054Z,1562807323.054 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:43.841Z,1562807323.841 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:44.229Z,1562807324.229 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:47.106Z,1562807327.106 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:47.231Z,1562807327.231 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.acoustic_contact_range
2019-07-11T01:08:47.455Z,1562807327.455 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:08:51.143Z,1562807331.143 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:51.904Z,1562807331.904 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:52.309Z,1562807332.309 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:55.148Z,1562807335.148 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:08:55.196Z,1562807335.196 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:55.939Z,1562807335.939 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:08:56.349Z,1562807336.349 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:08:59.175Z,1562807339.175 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:08:59.211Z,1562807339.211 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:08:59.985Z,1562807339.985 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:09:00.389Z,1562807340.389 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:09:03.215Z,1562807343.215 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:09:03.241Z,1562807343.241 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:09:04.021Z,1562807344.021 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:09:04.425Z,1562807344.425 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:09:04.903Z,1562807344.903 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 125.940002 m
2019-07-11T01:09:08.905Z,1562807348.905 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:09:09.681Z,1562807349.681 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:09:10.081Z,1562807350.081 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:09:12.911Z,1562807352.911 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:09:13.107Z,1562807353.107 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:09:13.721Z,1562807353.721 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:09:14.121Z,1562807354.121 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:09:14.578Z,1562807354.578 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 125.880005 m
2019-07-11T01:09:18.594Z,1562807358.594 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:09:19.377Z,1562807359.377 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:09:19.783Z,1562807359.783 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:09:20.223Z,1562807360.223 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 4.800000 m
2019-07-11T01:09:24.256Z,1562807364.256 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:09:25.026Z,1562807365.026 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:09:25.433Z,1562807365.433 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:09:28.263Z,1562807368.263 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:09:28.289Z,1562807368.289 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:09:29.073Z,1562807369.073 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:09:29.489Z,1562807369.489 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:09:32.088Z,1562807372.088 [CommandLine](IMPORTANT): got command stop
2019-07-11T01:09:32.088Z,1562807372.088 [CommandLine](IMPORTANT): Scheduling is paused
2019-07-11T01:09:32.088Z,1562807372.088 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-07-11T01:09:32.305Z,1562807372.305 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:09:32.345Z,1562807372.345 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:09:32.346Z,1562807372.346 [MissionManager](INFO): MissionManager is completed.
2019-07-11T01:09:32.347Z,1562807372.347 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL] Stopped
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:A.Pitch] Stopped
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:B.SetSpeed] Stopped
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:C.] Stopped
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:RequestRepeater] Stopped
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-07-11T01:09:32.347Z,1562807372.347 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:09:32.753Z,1562807372.753 [MissionManager](IMPORTANT): Started mission Default
2019-07-11T01:09:32.753Z,1562807372.753 [Default] Running Loop=1
2019-07-11T01:09:32.754Z,1562807372.754 [Default](DEBUG): Aggregate::initialize Default
2019-07-11T01:09:32.754Z,1562807372.754 [Default:B.GoToSurface] Running Loop=1
2019-07-11T01:09:32.754Z,1562807372.754 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:09:32.754Z,1562807372.754 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:09:32.754Z,1562807372.754 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:09:32.755Z,1562807372.755 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:09:32.755Z,1562807372.755 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:09:32.755Z,1562807372.755 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:09:32.756Z,1562807372.756 [Default:A.Wait] Running Loop=1
2019-07-11T01:09:32.756Z,1562807372.756 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:09:46.209Z,1562807386.209 [Default:A.Wait](INFO): Done Waiting.
2019-07-11T01:09:46.209Z,1562807386.209 [Default:A.Wait] Stopped
2019-07-11T01:09:46.209Z,1562807386.209 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:09:46.482Z,1562807386.482 [Default:CheckIn] Running Loop=1
2019-07-11T01:09:46.482Z,1562807386.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-11T01:09:46.482Z,1562807386.482 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-11T01:09:58.961Z,1562807398.961 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.detectionThreshold 75.000000 count
2019-07-11T01:10:02.792Z,1562807402.792 [CommandLine](IMPORTANT): got command run ./Missions/DUSBL_Tracking.xml
2019-07-11T01:10:02.793Z,1562807402.793 [MissionManager](INFO): Loading Mission: ./Missions/DUSBL_Tracking.xml
2019-07-11T01:10:02.847Z,1562807402.847 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 5.000000 min
2019-07-11T01:10:02.849Z,1562807402.849 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-07-11T01:10:02.852Z,1562807402.852 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-07-11T01:10:02.854Z,1562807402.854 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-07-11T01:10:02.856Z,1562807402.856 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-07-11T01:10:02.857Z,1562807402.857 [DUSBL:A.Pitch](DEBUG): Construct.
2019-07-11T01:10:02.861Z,1562807402.861 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-07-11T01:10:02.876Z,1562807402.876 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-07-11T01:10:02.879Z,1562807402.879 [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>5</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-07-11T01:10:02.881Z,1562807402.881 [CommandLine](IMPORTANT): Running ./Missions/DUSBL_Tracking.xml
2019-07-11T01:10:03.037Z,1562807403.037 [Default] Stopped
2019-07-11T01:10:03.037Z,1562807403.037 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-11T01:10:03.037Z,1562807403.037 [Default:B.GoToSurface] Stopped
2019-07-11T01:10:03.037Z,1562807403.037 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-11T01:10:03.037Z,1562807403.037 [Default:CheckIn] Stopped
2019-07-11T01:10:03.037Z,1562807403.037 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-11T01:10:03.038Z,1562807403.038 [Default:CheckIn:Read_GPS] Stopped
2019-07-11T01:10:03.038Z,1562807403.038 [MissionManager](IMPORTANT): Started mission DUSBL
2019-07-11T01:10:03.038Z,1562807403.038 [DUSBL] Running Loop=1
2019-07-11T01:10:03.038Z,1562807403.038 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-07-11T01:10:03.038Z,1562807403.038 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:10:03.038Z,1562807403.038 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-07-11T01:10:03.039Z,1562807403.039 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:10:03.039Z,1562807403.039 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-07-11T01:10:03.039Z,1562807403.039 [DUSBL:C.] Running Loop=1
2019-07-11T01:10:03.039Z,1562807403.039 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-07-11T01:10:03.039Z,1562807403.039 [DUSBL:RequestRepeater] Running Loop=1
2019-07-11T01:10:03.039Z,1562807403.039 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-07-11T01:10:03.040Z,1562807403.040 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-07-11T01:10:03.040Z,1562807403.040 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:10:03.040Z,1562807403.040 [DUSBL:C.] Running Loop=1
2019-07-11T01:10:03.040Z,1562807403.040 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:10:03.040Z,1562807403.040 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:10:07.105Z,1562807407.105 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:07.856Z,1562807407.856 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:08.265Z,1562807408.265 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:11.088Z,1562807411.088 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:11.159Z,1562807411.159 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:11.893Z,1562807411.893 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:12.301Z,1562807412.301 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:15.127Z,1562807415.127 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:15.182Z,1562807415.182 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:15.933Z,1562807415.933 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:16.342Z,1562807416.342 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:19.163Z,1562807419.163 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:19.199Z,1562807419.199 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:19.977Z,1562807419.977 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:20.377Z,1562807420.377 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:23.216Z,1562807423.216 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:23.258Z,1562807423.258 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:24.013Z,1562807424.013 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:24.417Z,1562807424.417 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:27.247Z,1562807427.247 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:27.310Z,1562807427.310 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:28.053Z,1562807428.053 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:28.461Z,1562807428.461 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:31.284Z,1562807431.284 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:31.716Z,1562807431.716 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:32.501Z,1562807432.501 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:32.905Z,1562807432.905 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:35.738Z,1562807435.738 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:35.764Z,1562807435.764 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:36.537Z,1562807436.537 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:36.946Z,1562807436.946 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:39.771Z,1562807439.771 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:10:39.862Z,1562807439.862 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:40.581Z,1562807440.581 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:40.981Z,1562807440.981 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:10:41.255Z,1562807441.255 [CommandLine](IMPORTANT): got command stop
2019-07-11T01:10:41.255Z,1562807441.255 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-07-11T01:10:41.432Z,1562807441.432 [MissionManager](INFO): MissionManager is completed.
2019-07-11T01:10:41.433Z,1562807441.433 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL] Stopped
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:A.Pitch] Stopped
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:B.SetSpeed] Stopped
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:C.] Stopped
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:RequestRepeater] Stopped
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-07-11T01:10:41.433Z,1562807441.433 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:10:41.842Z,1562807441.842 [RDI_Pathfinder](ERROR): DVL BIT error. See manual. Result code: 93
2019-07-11T01:10:41.845Z,1562807441.845 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,    -4,   +10,    -1,-32768,A
2019-07-11T01:10:41.853Z,1562807441.853 [MissionManager](IMPORTANT): Started mission Default
2019-07-11T01:10:41.854Z,1562807441.854 [Default] Running Loop=1
2019-07-11T01:10:41.854Z,1562807441.854 [Default](DEBUG): Aggregate::initialize Default
2019-07-11T01:10:41.854Z,1562807441.854 [Default:B.GoToSurface] Running Loop=1
2019-07-11T01:10:41.854Z,1562807441.854 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:10:41.855Z,1562807441.855 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:10:41.855Z,1562807441.855 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:10:41.855Z,1562807441.855 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:10:41.855Z,1562807441.855 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:10:41.856Z,1562807441.856 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:10:41.856Z,1562807441.856 [Default:A.Wait] Running Loop=1
2019-07-11T01:10:41.856Z,1562807441.856 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:10:50.436Z,1562807450.436 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.detectionThreshold 55.000000 count
2019-07-11T01:10:54.516Z,1562807454.516 [CommandLine](IMPORTANT): got command run ./Missions/DUSBL_Tracking.xml
2019-07-11T01:10:54.517Z,1562807454.517 [MissionManager](INFO): Loading Mission: ./Missions/DUSBL_Tracking.xml
2019-07-11T01:10:54.541Z,1562807454.541 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 5.000000 min
2019-07-11T01:10:54.544Z,1562807454.544 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-07-11T01:10:54.546Z,1562807454.546 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-07-11T01:10:54.548Z,1562807454.548 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-07-11T01:10:54.550Z,1562807454.550 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-07-11T01:10:54.551Z,1562807454.551 [DUSBL:A.Pitch](DEBUG): Construct.
2019-07-11T01:10:54.555Z,1562807454.555 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-07-11T01:10:54.611Z,1562807454.611 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-07-11T01:10:54.619Z,1562807454.619 [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>5</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-07-11T01:10:54.621Z,1562807454.621 [CommandLine](IMPORTANT): Running ./Missions/DUSBL_Tracking.xml
2019-07-11T01:10:54.745Z,1562807454.745 [Default] Stopped
2019-07-11T01:10:54.745Z,1562807454.745 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-11T01:10:54.745Z,1562807454.745 [Default:A.Wait] Stopped
2019-07-11T01:10:54.745Z,1562807454.745 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:10:54.746Z,1562807454.746 [Default:B.GoToSurface] Stopped
2019-07-11T01:10:54.746Z,1562807454.746 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-11T01:10:54.746Z,1562807454.746 [MissionManager](IMPORTANT): Started mission DUSBL
2019-07-11T01:10:54.748Z,1562807454.748 [DUSBL] Running Loop=1
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL:C.] Running Loop=1
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-07-11T01:10:54.749Z,1562807454.749 [DUSBL:RequestRepeater] Running Loop=1
2019-07-11T01:10:54.750Z,1562807454.750 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-07-11T01:10:54.750Z,1562807454.750 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-07-11T01:10:54.750Z,1562807454.750 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:10:54.750Z,1562807454.750 [DUSBL:C.] Running Loop=1
2019-07-11T01:10:54.751Z,1562807454.751 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:10:54.751Z,1562807454.751 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:10:58.786Z,1562807458.786 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:10:59.568Z,1562807459.568 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:10:59.970Z,1562807459.970 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:02.807Z,1562807462.807 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:02.853Z,1562807462.853 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:03.609Z,1562807463.609 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:04.013Z,1562807464.013 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:06.844Z,1562807466.844 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:06.903Z,1562807466.903 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:07.247Z,1562807467.247 [NAL9602](INFO): SBD MO Status=2, MOMSN=8111, MT Status=2, MTMSN=0
2019-07-11T01:11:07.247Z,1562807467.247 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-11T01:11:07.649Z,1562807467.649 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:08.049Z,1562807468.049 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:10.879Z,1562807470.879 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:10.944Z,1562807470.944 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:11.688Z,1562807471.688 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:12.088Z,1562807472.088 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:14.919Z,1562807474.919 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:14.994Z,1562807474.994 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:15.729Z,1562807475.729 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:16.129Z,1562807476.129 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:18.959Z,1562807478.959 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:18.995Z,1562807478.995 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:19.768Z,1562807479.768 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:20.179Z,1562807480.179 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:22.997Z,1562807482.997 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:23.033Z,1562807483.033 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:23.839Z,1562807483.839 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:24.213Z,1562807484.213 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:27.143Z,1562807487.143 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:27.443Z,1562807487.443 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:31.506Z,1562807491.506 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:32.288Z,1562807492.288 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:32.693Z,1562807492.693 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:35.523Z,1562807495.523 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:11:35.549Z,1562807495.549 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:36.333Z,1562807496.333 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:36.737Z,1562807496.737 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:38.305Z,1562807498.305 [CommandLine](IMPORTANT): got command stop
2019-07-11T01:11:38.305Z,1562807498.305 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-07-11T01:11:38.376Z,1562807498.376 [MissionManager](INFO): MissionManager is completed.
2019-07-11T01:11:38.376Z,1562807498.376 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-07-11T01:11:38.376Z,1562807498.376 [DUSBL] Stopped
2019-07-11T01:11:38.376Z,1562807498.376 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-07-11T01:11:38.376Z,1562807498.376 [DUSBL:A.Pitch] Stopped
2019-07-11T01:11:38.376Z,1562807498.376 [DUSBL:B.SetSpeed] Stopped
2019-07-11T01:11:38.376Z,1562807498.376 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-07-11T01:11:38.377Z,1562807498.377 [DUSBL:C.] Stopped
2019-07-11T01:11:38.377Z,1562807498.377 [DUSBL:RequestRepeater] Stopped
2019-07-11T01:11:38.377Z,1562807498.377 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-07-11T01:11:38.377Z,1562807498.377 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-07-11T01:11:38.377Z,1562807498.377 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:11:38.785Z,1562807498.785 [MissionManager](IMPORTANT): Started mission Default
2019-07-11T01:11:38.785Z,1562807498.785 [Default] Running Loop=1
2019-07-11T01:11:38.786Z,1562807498.786 [Default](DEBUG): Aggregate::initialize Default
2019-07-11T01:11:38.786Z,1562807498.786 [Default:B.GoToSurface] Running Loop=1
2019-07-11T01:11:38.786Z,1562807498.786 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:11:38.786Z,1562807498.786 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:11:38.786Z,1562807498.786 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:11:38.787Z,1562807498.787 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:11:38.787Z,1562807498.787 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:11:38.787Z,1562807498.787 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:11:38.788Z,1562807498.788 [Default:A.Wait] Running Loop=1
2019-07-11T01:11:38.788Z,1562807498.788 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:11:48.115Z,1562807508.115 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.detectionThreshold 35.000000 count
2019-07-11T01:11:52.135Z,1562807512.135 [Default:A.Wait](INFO): Done Waiting.
2019-07-11T01:11:52.135Z,1562807512.135 [Default:A.Wait] Stopped
2019-07-11T01:11:52.135Z,1562807512.135 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:11:52.518Z,1562807512.518 [Default:CheckIn] Running Loop=1
2019-07-11T01:11:52.518Z,1562807512.518 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-11T01:11:52.519Z,1562807512.519 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-11T01:11:52.898Z,1562807512.898 [NAL9602](INFO): SBD MO Status=2, MOMSN=8111, MT Status=2, MTMSN=0
2019-07-11T01:11:52.898Z,1562807512.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-11T01:11:53.332Z,1562807513.332 [CommandLine](IMPORTANT): got command run ./Missions/DUSBL_Tracking.xml
2019-07-11T01:11:53.333Z,1562807513.333 [MissionManager](INFO): Loading Mission: ./Missions/DUSBL_Tracking.xml
2019-07-11T01:11:53.385Z,1562807513.385 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 5.000000 min
2019-07-11T01:11:53.388Z,1562807513.388 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-07-11T01:11:53.390Z,1562807513.390 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-07-11T01:11:53.392Z,1562807513.392 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-07-11T01:11:53.394Z,1562807513.394 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-07-11T01:11:53.395Z,1562807513.395 [DUSBL:A.Pitch](DEBUG): Construct.
2019-07-11T01:11:53.399Z,1562807513.399 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-07-11T01:11:53.412Z,1562807513.412 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-07-11T01:11:53.444Z,1562807513.444 [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>5</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-07-11T01:11:53.450Z,1562807513.450 [CommandLine](IMPORTANT): Running ./Missions/DUSBL_Tracking.xml
2019-07-11T01:11:53.823Z,1562807513.823 [Default] Stopped
2019-07-11T01:11:53.823Z,1562807513.823 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-11T01:11:53.824Z,1562807513.824 [Default:B.GoToSurface] Stopped
2019-07-11T01:11:53.824Z,1562807513.824 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-11T01:11:53.824Z,1562807513.824 [Default:CheckIn] Stopped
2019-07-11T01:11:53.825Z,1562807513.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-11T01:11:53.825Z,1562807513.825 [Default:CheckIn:Read_GPS] Stopped
2019-07-11T01:11:53.825Z,1562807513.825 [MissionManager](IMPORTANT): Started mission DUSBL
2019-07-11T01:11:53.842Z,1562807513.842 [DUSBL] Running Loop=1
2019-07-11T01:11:53.842Z,1562807513.842 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-07-11T01:11:53.842Z,1562807513.842 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:11:53.843Z,1562807513.843 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-07-11T01:11:53.843Z,1562807513.843 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:11:53.843Z,1562807513.843 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-07-11T01:11:53.843Z,1562807513.843 [DUSBL:C.] Running Loop=1
2019-07-11T01:11:53.843Z,1562807513.843 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-07-11T01:11:53.843Z,1562807513.843 [DUSBL:RequestRepeater] Running Loop=1
2019-07-11T01:11:53.843Z,1562807513.843 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-07-11T01:11:53.844Z,1562807513.844 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-07-11T01:11:53.844Z,1562807513.844 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:11:53.844Z,1562807513.844 [DUSBL:C.] Running Loop=1
2019-07-11T01:11:53.844Z,1562807513.844 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:11:53.845Z,1562807513.845 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:11:58.176Z,1562807518.176 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:11:58.957Z,1562807518.957 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:11:59.365Z,1562807519.365 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:11:59.860Z,1562807519.860 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 9.240001 m
2019-07-11T01:12:03.869Z,1562807523.869 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:04.607Z,1562807524.607 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:05.014Z,1562807525.014 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:07.848Z,1562807527.848 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:12:07.933Z,1562807527.933 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:08.649Z,1562807528.649 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:09.053Z,1562807529.053 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:09.530Z,1562807529.530 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 9.299998 m
2019-07-11T01:12:13.595Z,1562807533.595 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:14.308Z,1562807534.308 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:14.714Z,1562807534.714 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:17.535Z,1562807537.535 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:12:17.977Z,1562807537.977 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:18.753Z,1562807538.753 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:19.157Z,1562807539.157 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:21.980Z,1562807541.980 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:12:22.031Z,1562807542.031 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:22.793Z,1562807542.793 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:23.194Z,1562807543.194 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:26.020Z,1562807546.020 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:12:26.057Z,1562807546.057 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:26.863Z,1562807546.863 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:27.233Z,1562807547.233 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:30.109Z,1562807550.109 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:30.471Z,1562807550.471 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:12:30.671Z,1562807550.671 [CommandLine](IMPORTANT): got command stop
2019-07-11T01:12:30.671Z,1562807550.671 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-07-11T01:12:30.921Z,1562807550.921 [MissionManager](INFO): MissionManager is completed.
2019-07-11T01:12:30.921Z,1562807550.921 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL] Stopped
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:A.Pitch] Stopped
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:B.SetSpeed] Stopped
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:C.] Stopped
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:RequestRepeater] Stopped
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-07-11T01:12:30.921Z,1562807550.921 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:12:31.303Z,1562807551.303 [MissionManager](IMPORTANT): Started mission Default
2019-07-11T01:12:31.303Z,1562807551.303 [Default] Running Loop=1
2019-07-11T01:12:31.304Z,1562807551.304 [Default](DEBUG): Aggregate::initialize Default
2019-07-11T01:12:31.304Z,1562807551.304 [Default:B.GoToSurface] Running Loop=1
2019-07-11T01:12:31.304Z,1562807551.304 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:12:31.304Z,1562807551.304 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:12:31.304Z,1562807551.304 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:12:31.305Z,1562807551.305 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:12:31.305Z,1562807551.305 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:12:31.305Z,1562807551.305 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:12:31.306Z,1562807551.306 [Default:A.Wait] Running Loop=1
2019-07-11T01:12:31.306Z,1562807551.306 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:12:36.126Z,1562807556.126 [NAL9602](INFO): SBD MO Status=2, MOMSN=8111, MT Status=2, MTMSN=0
2019-07-11T01:12:36.126Z,1562807556.126 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-11T01:12:38.008Z,1562807558.008 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.detectionThreshold 15.000000 count
2019-07-11T01:12:40.181Z,1562807560.181 [CommandLine](IMPORTANT): got command run ./Missions/DUSBL_Tracking.xml
2019-07-11T01:12:40.181Z,1562807560.181 [MissionManager](INFO): Loading Mission: ./Missions/DUSBL_Tracking.xml
2019-07-11T01:12:40.229Z,1562807560.229 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 5.000000 min
2019-07-11T01:12:40.235Z,1562807560.235 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-07-11T01:12:40.238Z,1562807560.238 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-07-11T01:12:40.248Z,1562807560.248 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-07-11T01:12:40.251Z,1562807560.251 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-07-11T01:12:40.252Z,1562807560.252 [DUSBL:A.Pitch](DEBUG): Construct.
2019-07-11T01:12:40.256Z,1562807560.256 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-07-11T01:12:40.268Z,1562807560.268 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-07-11T01:12:40.296Z,1562807560.296 [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>5</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-07-11T01:12:40.302Z,1562807560.302 [CommandLine](IMPORTANT): Running ./Missions/DUSBL_Tracking.xml
2019-07-11T01:12:40.674Z,1562807560.674 [Default] Stopped
2019-07-11T01:12:40.674Z,1562807560.674 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-11T01:12:40.674Z,1562807560.674 [Default:A.Wait] Stopped
2019-07-11T01:12:40.674Z,1562807560.674 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:12:40.674Z,1562807560.674 [Default:B.GoToSurface] Stopped
2019-07-11T01:12:40.674Z,1562807560.674 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-11T01:12:40.674Z,1562807560.674 [MissionManager](IMPORTANT): Started mission DUSBL
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL] Running Loop=1
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL:C.] Running Loop=1
2019-07-11T01:12:40.675Z,1562807560.675 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-07-11T01:12:40.676Z,1562807560.676 [DUSBL:RequestRepeater] Running Loop=1
2019-07-11T01:12:40.676Z,1562807560.676 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-07-11T01:12:40.676Z,1562807560.676 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-07-11T01:12:40.676Z,1562807560.676 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:12:40.676Z,1562807560.676 [DUSBL:C.] Running Loop=1
2019-07-11T01:12:40.677Z,1562807560.677 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:12:40.677Z,1562807560.677 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:12:41.030Z,1562807561.030 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-07-11T01:12:41.041Z,1562807561.041 [BPC1](INFO): Received data from all battery sticks.
2019-07-11T01:12:45.045Z,1562807565.045 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:45.838Z,1562807565.838 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:46.225Z,1562807566.225 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:46.623Z,1562807566.623 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-07-11T01:12:49.079Z,1562807569.079 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:49.463Z,1562807569.463 [NAL9602](INFO): SBD MO Status=2, MOMSN=8111, MT Status=2, MTMSN=0
2019-07-11T01:12:49.463Z,1562807569.463 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-11T01:12:49.856Z,1562807569.856 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:50.267Z,1562807570.267 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:51.069Z,1562807571.069 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-11T01:12:53.121Z,1562807573.121 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:57.169Z,1562807577.169 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:12:57.941Z,1562807577.941 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:12:58.345Z,1562807578.345 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:12:58.741Z,1562807578.741 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-07-11T01:13:01.226Z,1562807581.226 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:01.975Z,1562807581.975 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:02.385Z,1562807582.385 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:02.807Z,1562807582.807 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-07-11T01:13:05.248Z,1562807585.248 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:06.021Z,1562807586.021 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:06.432Z,1562807586.432 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:06.844Z,1562807586.844 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-07-11T01:13:09.270Z,1562807589.270 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:10.061Z,1562807590.061 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:10.462Z,1562807590.462 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:13.324Z,1562807593.324 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:17.354Z,1562807597.354 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:18.137Z,1562807598.137 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:18.541Z,1562807598.541 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:21.396Z,1562807601.396 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:21.779Z,1562807601.779 [NAL9602](INFO): Powering down
2019-07-11T01:13:25.436Z,1562807605.436 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:26.220Z,1562807606.220 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:26.625Z,1562807606.625 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:29.482Z,1562807609.482 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:33.522Z,1562807613.522 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:34.297Z,1562807614.297 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:34.701Z,1562807614.701 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:37.554Z,1562807617.554 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:41.633Z,1562807621.633 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:42.382Z,1562807622.382 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:42.832Z,1562807622.832 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:43.194Z,1562807623.194 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-07-11T01:13:45.634Z,1562807625.634 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:13:46.417Z,1562807626.417 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:13:46.848Z,1562807626.848 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:13:48.535Z,1562807628.535 [CommandLine](IMPORTANT): got command stop
2019-07-11T01:13:48.535Z,1562807628.535 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-07-11T01:13:48.895Z,1562807628.895 [MissionManager](INFO): MissionManager is completed.
2019-07-11T01:13:48.895Z,1562807628.895 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-07-11T01:13:48.895Z,1562807628.895 [DUSBL] Stopped
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:A.Pitch] Stopped
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:B.SetSpeed] Stopped
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:C.] Stopped
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:RequestRepeater] Stopped
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-07-11T01:13:48.896Z,1562807628.896 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:13:49.269Z,1562807629.269 [MissionManager](IMPORTANT): Started mission Default
2019-07-11T01:13:49.269Z,1562807629.269 [Default] Running Loop=1
2019-07-11T01:13:49.270Z,1562807629.270 [Default](DEBUG): Aggregate::initialize Default
2019-07-11T01:13:49.270Z,1562807629.270 [Default:B.GoToSurface] Running Loop=1
2019-07-11T01:13:49.270Z,1562807629.270 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:13:49.270Z,1562807629.270 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:13:49.270Z,1562807629.270 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:13:49.271Z,1562807629.271 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:13:49.271Z,1562807629.271 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:13:49.271Z,1562807629.271 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:13:49.272Z,1562807629.272 [Default:A.Wait] Running Loop=1
2019-07-11T01:13:49.272Z,1562807629.272 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:13:59.839Z,1562807639.839 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.detectionThreshold 25.000000 count
2019-07-11T01:14:02.610Z,1562807642.610 [Default:A.Wait](INFO): Done Waiting.
2019-07-11T01:14:02.610Z,1562807642.610 [Default:A.Wait] Stopped
2019-07-11T01:14:02.610Z,1562807642.610 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:14:02.663Z,1562807642.663 [CommandLine](IMPORTANT): got command run ./Missions/DUSBL_Tracking.xml
2019-07-11T01:14:02.664Z,1562807642.664 [MissionManager](INFO): Loading Mission: ./Missions/DUSBL_Tracking.xml
2019-07-11T01:14:02.713Z,1562807642.713 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 5.000000 min
2019-07-11T01:14:02.716Z,1562807642.716 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-07-11T01:14:02.718Z,1562807642.718 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 4.000000 s
2019-07-11T01:14:02.720Z,1562807642.720 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-07-11T01:14:02.737Z,1562807642.737 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-07-11T01:14:02.738Z,1562807642.738 [DUSBL:A.Pitch](DEBUG): Construct.
2019-07-11T01:14:02.758Z,1562807642.758 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-07-11T01:14:02.789Z,1562807642.789 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-07-11T01:14:02.811Z,1562807642.811 [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>5</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-07-11T01:14:02.820Z,1562807642.820 [CommandLine](IMPORTANT): Running ./Missions/DUSBL_Tracking.xml
2019-07-11T01:14:03.012Z,1562807643.012 [Default] Stopped
2019-07-11T01:14:03.013Z,1562807643.013 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-11T01:14:03.013Z,1562807643.013 [Default:B.GoToSurface] Stopped
2019-07-11T01:14:03.013Z,1562807643.013 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-11T01:14:03.013Z,1562807643.013 [MissionManager](IMPORTANT): Started mission DUSBL
2019-07-11T01:14:03.013Z,1562807643.013 [DUSBL] Running Loop=1
2019-07-11T01:14:03.013Z,1562807643.013 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-07-11T01:14:03.013Z,1562807643.013 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:14:03.013Z,1562807643.013 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-07-11T01:14:03.014Z,1562807643.014 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:14:03.014Z,1562807643.014 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-07-11T01:14:03.014Z,1562807643.014 [DUSBL:C.] Running Loop=1
2019-07-11T01:14:03.014Z,1562807643.014 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-07-11T01:14:03.014Z,1562807643.014 [DUSBL:RequestRepeater] Running Loop=1
2019-07-11T01:14:03.015Z,1562807643.015 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-07-11T01:14:03.015Z,1562807643.015 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-07-11T01:14:03.015Z,1562807643.015 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:14:03.015Z,1562807643.015 [DUSBL:C.] Running Loop=1
2019-07-11T01:14:03.015Z,1562807643.015 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-11T01:14:03.016Z,1562807643.016 [DUSBL:A.Pitch] Running Loop=1
2019-07-11T01:14:07.053Z,1562807647.053 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:07.843Z,1562807647.843 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:08.233Z,1562807648.233 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:08.700Z,1562807648.700 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 16.139999 m
2019-07-11T01:14:12.703Z,1562807652.703 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:13.488Z,1562807653.488 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:13.889Z,1562807653.889 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:14.354Z,1562807654.354 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 8.939999 m
2019-07-11T01:14:18.359Z,1562807658.359 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:19.141Z,1562807659.141 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:19.549Z,1562807659.549 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:19.999Z,1562807659.999 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:14:24.029Z,1562807664.029 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:24.807Z,1562807664.807 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:24.861Z,1562807664.861 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-07-11T01:14:24.861Z,1562807664.861 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,    +5,   -57,  :BE,    +5,   -57,    -3,A
2019-07-11T01:14:25.201Z,1562807665.201 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:25.646Z,1562807665.646 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 9.479997 m
2019-07-11T01:14:29.670Z,1562807669.670 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:30.452Z,1562807670.452 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:30.866Z,1562807670.866 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:31.327Z,1562807671.327 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 8.999999 m
2019-07-11T01:14:35.327Z,1562807675.327 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:36.113Z,1562807676.113 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:36.517Z,1562807676.517 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:36.967Z,1562807676.967 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:14:40.997Z,1562807680.997 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:41.769Z,1562807681.769 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:42.173Z,1562807682.173 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:42.612Z,1562807682.612 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 9.419999 m
2019-07-11T01:14:46.640Z,1562807686.640 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:47.421Z,1562807687.421 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:47.840Z,1562807687.840 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:48.298Z,1562807688.298 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 3.360000 m
2019-07-11T01:14:52.294Z,1562807692.294 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:53.081Z,1562807693.081 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:53.485Z,1562807693.485 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:53.949Z,1562807693.949 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 8.999999 m
2019-07-11T01:14:57.957Z,1562807697.957 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:14:58.737Z,1562807698.737 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:14:59.137Z,1562807699.137 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:14:59.586Z,1562807699.586 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 9.419999 m
2019-07-11T01:15:03.610Z,1562807703.610 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:04.388Z,1562807704.388 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:04.805Z,1562807704.805 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:05.277Z,1562807705.277 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:15:09.266Z,1562807709.266 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:10.045Z,1562807710.045 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:10.455Z,1562807710.455 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:10.915Z,1562807710.915 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 44.459999 m
2019-07-11T01:15:14.941Z,1562807714.941 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:15.705Z,1562807715.705 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:16.105Z,1562807716.105 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:16.561Z,1562807716.561 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 8.939999 m
2019-07-11T01:15:20.577Z,1562807720.577 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:21.356Z,1562807721.356 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:21.765Z,1562807721.765 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:22.238Z,1562807722.238 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.480000 m
2019-07-11T01:15:26.233Z,1562807726.233 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:27.021Z,1562807727.021 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:27.420Z,1562807727.420 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:27.892Z,1562807727.892 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 11.159998 m
2019-07-11T01:15:31.896Z,1562807731.896 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:32.669Z,1562807732.669 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:33.073Z,1562807733.073 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:33.516Z,1562807733.516 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:15:37.550Z,1562807737.550 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:38.324Z,1562807738.324 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:38.730Z,1562807738.730 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:39.206Z,1562807739.206 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:15:43.205Z,1562807743.205 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:43.984Z,1562807743.984 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:44.385Z,1562807744.385 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:44.909Z,1562807744.909 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.480000 m
2019-07-11T01:15:48.897Z,1562807748.897 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:49.641Z,1562807749.641 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:50.041Z,1562807750.041 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:50.484Z,1562807750.484 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 55.619995 m
2019-07-11T01:15:54.518Z,1562807754.518 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:55.296Z,1562807755.296 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:55.701Z,1562807755.701 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:15:58.527Z,1562807758.527 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-11T01:15:58.552Z,1562807758.552 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:15:59.331Z,1562807759.331 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:15:59.737Z,1562807759.737 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:16:00.192Z,1562807760.192 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:16:04.225Z,1562807764.225 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:16:04.992Z,1562807764.992 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:16:05.394Z,1562807765.394 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:16:05.837Z,1562807765.837 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-07-11T01:16:05.838Z,1562807765.838 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,    +2,   -35A
2019-07-11T01:16:05.905Z,1562807765.905 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.359999 m
2019-07-11T01:16:10.261Z,1562807770.261 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:16:11.052Z,1562807771.052 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:16:11.457Z,1562807771.457 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:16:11.926Z,1562807771.926 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:16:15.933Z,1562807775.934 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:16:16.705Z,1562807776.705 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:16:17.109Z,1562807777.109 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:16:17.553Z,1562807777.553 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 27.420002 m
2019-07-11T01:16:21.587Z,1562807781.587 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:16:22.365Z,1562807782.365 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:16:22.769Z,1562807782.769 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:16:23.219Z,1562807783.219 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 11.100000 m
2019-07-11T01:16:27.236Z,1562807787.236 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:16:28.020Z,1562807788.020 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:16:28.425Z,1562807788.425 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:16:28.899Z,1562807788.899 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 9.419999 m
2019-07-11T01:16:32.906Z,1562807792.906 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-11T01:16:33.673Z,1562807793.673 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-11T01:16:34.077Z,1562807794.077 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-11T01:16:34.517Z,1562807794.517 [Reporter](INFO): DUSBL_Hydroid.acoustic_contact_range 9.359999 m
2019-07-11T01:16:36.376Z,1562807796.376 [CommandLine](IMPORTANT): got command stop
2019-07-11T01:16:36.376Z,1562807796.376 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-07-11T01:16:36.531Z,1562807796.531 [MissionManager](INFO): MissionManager is completed.
2019-07-11T01:16:36.531Z,1562807796.531 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-07-11T01:16:36.531Z,1562807796.531 [DUSBL] Stopped
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:A.Pitch] Stopped
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:B.SetSpeed] Stopped
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:C.] Stopped
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:RequestRepeater] Stopped
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-07-11T01:16:36.532Z,1562807796.532 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:16:36.941Z,1562807796.941 [MissionManager](IMPORTANT): Started mission Default
2019-07-11T01:16:36.941Z,1562807796.941 [Default] Running Loop=1
2019-07-11T01:16:36.941Z,1562807796.941 [Default](DEBUG): Aggregate::initialize Default
2019-07-11T01:16:36.941Z,1562807796.941 [Default:B.GoToSurface] Running Loop=1
2019-07-11T01:16:36.941Z,1562807796.941 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-11T01:16:36.941Z,1562807796.941 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-11T01:16:36.942Z,1562807796.942 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-11T01:16:36.942Z,1562807796.942 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-11T01:16:36.943Z,1562807796.943 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-11T01:16:36.943Z,1562807796.943 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-11T01:16:36.943Z,1562807796.943 [Default:A.Wait] Running Loop=1
2019-07-11T01:16:36.943Z,1562807796.943 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-11T01:16:50.262Z,1562807810.262 [Default:A.Wait](INFO): Done Waiting.
2019-07-11T01:16:50.262Z,1562807810.262 [Default:A.Wait] Stopped
2019-07-11T01:16:50.262Z,1562807810.262 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-11T01:16:50.682Z,1562807810.682 [Default:CheckIn] Running Loop=1
2019-07-11T01:16:50.682Z,1562807810.682 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-11T01:16:50.682Z,1562807810.682 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-11T01:16:51.452Z,1562807811.452 [NAL9602](INFO): Powering up
2019-07-11T01:17:02.354Z,1562807822.354 [NAL9602](INFO): NAL9602 initialized
2019-07-11T01:17:03.174Z,1562807823.174 [NAL9602](DEBUG): Fix Requested