2019-05-08T18:13:15.155Z,1557339195.155 [Supervisor](DEBUG): Initializing supervisor.
2019-05-08T18:13:15.158Z,1557339195.158 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-08T18:13:15.159Z,1557339195.159 [SyncHandler](INFO): Protected caller Thread ID is 1306
2019-05-08T18:13:15.159Z,1557339195.159 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-08T18:13:15.160Z,1557339195.160 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-08T18:13:15.160Z,1557339195.160 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1307
2019-05-08T18:13:15.163Z,1557339195.163 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-08T18:13:15.174Z,1557339195.174 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-08T18:13:15.175Z,1557339195.175 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-08T18:13:15.175Z,1557339195.175 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1308
2019-05-08T18:13:15.176Z,1557339195.176 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-08T18:13:15.177Z,1557339195.177 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-08T18:13:15.178Z,1557339195.178 [logger ThreadHandler](INFO): Protected caller Thread ID is 1309
2019-05-08T18:13:15.180Z,1557339195.180 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-08T18:13:15.180Z,1557339195.180 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-08T18:13:15.182Z,1557339195.182 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-08T18:13:15.605Z,1557339195.605 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-08T18:13:15.605Z,1557339195.605 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-08T18:13:15.705Z,1557339195.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-08T18:13:15.705Z,1557339195.705 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-08T18:13:16.031Z,1557339196.031 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-08T18:13:16.032Z,1557339196.032 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-08T18:13:16.176Z,1557339196.176 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-08T18:13:16.176Z,1557339196.176 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-08T18:13:16.376Z,1557339196.376 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-08T18:13:16.376Z,1557339196.376 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-08T18:13:16.837Z,1557339196.837 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-08T18:13:16.838Z,1557339196.838 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-08T18:13:17.052Z,1557339197.052 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-08T18:13:17.053Z,1557339197.053 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-08T18:13:17.200Z,1557339197.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-08T18:13:17.201Z,1557339197.201 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-08T18:13:17.399Z,1557339197.399 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-08T18:13:17.400Z,1557339197.400 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-08T18:13:17.497Z,1557339197.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-08T18:13:17.498Z,1557339197.498 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-08T18:13:17.819Z,1557339197.819 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-08T18:13:17.820Z,1557339197.820 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-08T18:13:17.905Z,1557339197.905 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-08T18:13:18.116Z,1557339198.116 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-08T18:13:18.117Z,1557339198.117 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-08T18:13:19.149Z,1557339199.149 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-08T18:13:19.149Z,1557339199.149 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-08T18:13:19.749Z,1557339199.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-08T18:13:19.751Z,1557339199.751 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-08T18:13:19.752Z,1557339199.752 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-08T18:13:20.159Z,1557339200.159 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-08T18:13:20.656Z,1557339200.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-08T18:13:20.998Z,1557339200.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-08T18:13:21.244Z,1557339201.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-08T18:13:21.245Z,1557339201.245 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-08T18:13:21.333Z,1557339201.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-08T18:13:21.461Z,1557339201.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-08T18:13:21.624Z,1557339201.624 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-08T18:13:21.750Z,1557339201.750 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-08T18:13:21.889Z,1557339201.889 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-08T18:13:22.203Z,1557339202.203 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-08T18:13:22.446Z,1557339202.446 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-05-08T18:13:22.447Z,1557339202.447 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-08T18:13:22.460Z,1557339202.460 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-08T18:13:22.949Z,1557339202.949 [AHRS_M2] Loaded
2019-05-08T18:13:22.950Z,1557339202.950 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-08T18:13:23.025Z,1557339203.025 [DataOverHttps] Loaded
2019-05-08T18:13:23.025Z,1557339203.025 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-08T18:13:23.027Z,1557339203.027 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075A4E0
2019-05-08T18:13:23.027Z,1557339203.027 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1394
2019-05-08T18:13:23.040Z,1557339203.040 [Depth_Keller] Loaded
2019-05-08T18:13:23.040Z,1557339203.040 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-08T18:13:23.045Z,1557339203.045 [DropWeight] Loaded
2019-05-08T18:13:23.045Z,1557339203.045 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-08T18:13:23.109Z,1557339203.109 [DUSBL_Hydroid] Loaded
2019-05-08T18:13:23.109Z,1557339203.109 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-08T18:13:23.149Z,1557339203.149 [Micromodem] Loaded
2019-05-08T18:13:23.150Z,1557339203.150 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-08T18:13:23.254Z,1557339203.254 [NAL9602] Loaded
2019-05-08T18:13:23.254Z,1557339203.254 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-08T18:13:23.270Z,1557339203.270 [Onboard] Loaded
2019-05-08T18:13:23.270Z,1557339203.270 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-08T18:13:23.276Z,1557339203.276 [PowerOnly] Loaded
2019-05-08T18:13:23.276Z,1557339203.276 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-08T18:13:23.282Z,1557339203.282 [Radio_Surface] Loaded
2019-05-08T18:13:23.283Z,1557339203.283 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-08T18:13:23.284Z,1557339203.284 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078A4E0
2019-05-08T18:13:23.284Z,1557339203.284 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1395
2019-05-08T18:13:23.328Z,1557339203.328 [RDI_Pathfinder] Loaded
2019-05-08T18:13:23.328Z,1557339203.328 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-08T18:13:24.810Z,1557339204.810 [BPC1] Loaded
2019-05-08T18:13:24.810Z,1557339204.810 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-08T18:13:24.811Z,1557339204.811 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-08T18:13:24.811Z,1557339204.811 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-08T18:13:24.824Z,1557339204.824 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-08T18:13:24.824Z,1557339204.824 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-08T18:13:24.929Z,1557339204.929 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-08T18:13:24.929Z,1557339204.929 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-08T18:13:24.949Z,1557339204.949 [NavChart] Loaded
2019-05-08T18:13:24.949Z,1557339204.949 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-08T18:13:24.953Z,1557339204.953 [UniversalFixResidualReporter] Loaded
2019-05-08T18:13:24.954Z,1557339204.954 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-08T18:13:24.954Z,1557339204.954 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-08T18:13:24.955Z,1557339204.955 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-08T18:13:25.062Z,1557339205.062 [BuoyancyServo] Loaded
2019-05-08T18:13:25.062Z,1557339205.062 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-08T18:13:25.077Z,1557339205.077 [ElevatorServo] Loaded
2019-05-08T18:13:25.077Z,1557339205.077 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-08T18:13:25.092Z,1557339205.092 [MassServo] Loaded
2019-05-08T18:13:25.092Z,1557339205.092 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-08T18:13:25.107Z,1557339205.107 [RudderServo] Loaded
2019-05-08T18:13:25.108Z,1557339205.108 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-08T18:13:25.123Z,1557339205.123 [ThrusterServo] Loaded
2019-05-08T18:13:25.123Z,1557339205.123 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-08T18:13:25.123Z,1557339205.123 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-08T18:13:25.124Z,1557339205.124 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-08T18:13:25.368Z,1557339205.368 [CTD_NeilBrown] Loaded
2019-05-08T18:13:25.369Z,1557339205.369 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-08T18:13:25.370Z,1557339205.370 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408CC4E0
2019-05-08T18:13:25.370Z,1557339205.370 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1396
2019-05-08T18:13:25.414Z,1557339205.414 [WetLabsSeaOWL_UV_A] Loaded
2019-05-08T18:13:25.414Z,1557339205.414 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-08T18:13:25.415Z,1557339205.415 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0
2019-05-08T18:13:25.416Z,1557339205.416 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1397
2019-05-08T18:13:25.416Z,1557339205.416 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-08T18:13:25.417Z,1557339205.417 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-08T18:13:25.839Z,1557339205.839 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-08T18:13:25.840Z,1557339205.840 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-08T18:13:25.879Z,1557339205.879 [DepthRateCalculator] Loaded
2019-05-08T18:13:25.880Z,1557339205.880 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-08T18:13:25.885Z,1557339205.885 [PitchRateCalculator] Loaded
2019-05-08T18:13:25.885Z,1557339205.885 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-08T18:13:25.898Z,1557339205.898 [SpeedCalculator] Loaded
2019-05-08T18:13:25.898Z,1557339205.898 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-08T18:13:25.919Z,1557339205.919 [TempGradientCalculator] Loaded
2019-05-08T18:13:25.919Z,1557339205.919 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-08T18:13:25.924Z,1557339205.924 [YawRateCalculator] Loaded
2019-05-08T18:13:25.925Z,1557339205.925 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-08T18:13:25.965Z,1557339205.965 [ElevatorOffsetCalculator] Loaded
2019-05-08T18:13:25.965Z,1557339205.965 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-08T18:13:25.966Z,1557339205.966 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-08T18:13:25.966Z,1557339205.966 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-08T18:13:26.100Z,1557339206.100 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-08T18:13:26.123Z,1557339206.123 [SBIT] Loaded
2019-05-08T18:13:26.123Z,1557339206.123 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-08T18:13:26.124Z,1557339206.124 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-08T18:13:26.135Z,1557339206.135 [IBIT] Loaded
2019-05-08T18:13:26.135Z,1557339206.135 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-08T18:13:26.138Z,1557339206.138 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-08T18:13:26.274Z,1557339206.274 [CBIT] Loaded
2019-05-08T18:13:26.275Z,1557339206.275 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-08T18:13:26.275Z,1557339206.275 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-08T18:13:26.276Z,1557339206.276 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-08T18:13:26.345Z,1557339206.345 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-08T18:13:26.345Z,1557339206.345 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-08T18:13:26.443Z,1557339206.443 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-08T18:13:26.443Z,1557339206.443 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-08T18:13:26.508Z,1557339206.508 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-08T18:13:26.592Z,1557339206.592 [VerticalControl] Loaded
2019-05-08T18:13:26.592Z,1557339206.592 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-08T18:13:26.593Z,1557339206.593 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-08T18:13:26.650Z,1557339206.650 [HorizontalControl] Loaded
2019-05-08T18:13:26.651Z,1557339206.651 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-08T18:13:26.651Z,1557339206.651 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-08T18:13:26.653Z,1557339206.653 [SpeedControl] Loaded
2019-05-08T18:13:26.653Z,1557339206.653 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-08T18:13:26.654Z,1557339206.654 [LoopControl](DEBUG): Construct LoopControl.
2019-05-08T18:13:26.654Z,1557339206.654 [LoopControl] Loaded
2019-05-08T18:13:26.655Z,1557339206.655 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-08T18:13:26.655Z,1557339206.655 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-08T18:13:26.656Z,1557339206.656 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-08T18:13:26.682Z,1557339206.682 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-08T18:13:26.685Z,1557339206.685 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-08T18:13:26.686Z,1557339206.686 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-08T18:13:26.693Z,1557339206.693 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-08T18:13:26.694Z,1557339206.694 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD34E0
2019-05-08T18:13:26.694Z,1557339206.694 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1398
2019-05-08T18:13:26.699Z,1557339206.699 [Supervisor](INFO): Main Thread ID is 1305
2019-05-08T18:13:26.699Z,1557339206.699 [Supervisor](DEBUG): Running supervisor.
2019-05-08T18:13:26.700Z,1557339206.700 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1399
2019-05-08T18:13:26.703Z,1557339206.703 [controlThread ThreadHandler](INFO): Handler Thread ID is 1400
2019-05-08T18:13:26.703Z,1557339206.703 [controlThread](DEBUG): Initializing ControlThread
2019-05-08T18:13:26.710Z,1557339206.710 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-08T18:13:26.710Z,1557339206.710 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-08T18:13:26.711Z,1557339206.711 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-08T18:13:26.711Z,1557339206.711 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-08T18:13:26.712Z,1557339206.712 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-08T18:13:26.712Z,1557339206.712 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-08T18:13:26.712Z,1557339206.712 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-08T18:13:26.713Z,1557339206.713 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-08T18:13:26.713Z,1557339206.713 [SBIT](INFO): Initialize SBIT Component.
2019-05-08T18:13:26.714Z,1557339206.714 [SBIT](IMPORTANT): git: 2019-04-10-23-g672f59b
2019-05-08T18:13:26.714Z,1557339206.714 [SBIT](INFO): git hash: 672f59b3bb9ba34f4915fd4dcb9119316785292f
2019-05-08T18:13:26.714Z,1557339206.714 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-08T18:13:26.715Z,1557339206.715 [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-05-08T18:13:26.717Z,1557339206.717 [SBIT](INFO): Beginning SBIT in 44.000000 seconds.
2019-05-08T18:13:26.717Z,1557339206.717 [IBIT](INFO): Initialize IBIT Component.
2019-05-08T18:13:26.718Z,1557339206.718 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-08T18:13:26.719Z,1557339206.719 [logger ThreadHandler](INFO): Handler Thread ID is 1401
2019-05-08T18:13:26.730Z,1557339206.730 [CBIT](DEBUG): Initialized mux pins.
2019-05-08T18:13:26.730Z,1557339206.730 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-08T18:13:26.739Z,1557339206.739 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1402
2019-05-08T18:13:26.740Z,1557339206.740 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-08T18:13:26.751Z,1557339206.751 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1403
2019-05-08T18:13:26.754Z,1557339206.754 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-08T18:13:26.754Z,1557339206.754 [CBIT](DEBUG): Initializing heartbeat.
2019-05-08T18:13:26.763Z,1557339206.763 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1404
2019-05-08T18:13:26.764Z,1557339206.764 [CTD_NeilBrown](INFO): Powering down
2019-05-08T18:13:26.791Z,1557339206.791 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1405
2019-05-08T18:13:26.792Z,1557339206.792 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-08T18:13:26.820Z,1557339206.820 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1406
2019-05-08T18:13:26.824Z,1557339206.824 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-08T18:13:26.824Z,1557339206.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-08T18:13:26.824Z,1557339206.824 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-08T18:13:26.824Z,1557339206.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-08T18:13:26.824Z,1557339206.824 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-08T18:13:26.824Z,1557339206.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-08T18:13:26.825Z,1557339206.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-08T18:13:26.825Z,1557339206.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-08T18:13:26.825Z,1557339206.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-08T18:13:26.825Z,1557339206.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-08T18:13:26.825Z,1557339206.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-08T18:13:26.826Z,1557339206.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-08T18:13:26.826Z,1557339206.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-08T18:13:26.826Z,1557339206.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-08T18:13:26.826Z,1557339206.826 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-08T18:13:26.826Z,1557339206.826 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-08T18:13:26.827Z,1557339206.827 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-08T18:13:26.827Z,1557339206.827 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-08T18:13:26.862Z,1557339206.862 [CBIT](DEBUG): Backplane powered.
2019-05-08T18:13:26.863Z,1557339206.863 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-08T18:13:26.864Z,1557339206.864 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-08T18:13:26.865Z,1557339206.865 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-08T18:13:26.866Z,1557339206.866 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-08T18:13:26.866Z,1557339206.866 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-08T18:13:26.876Z,1557339206.876 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-08T18:13:26.903Z,1557339206.903 [MissionManager](DEBUG):
2019-05-08T18:13:26.904Z,1557339206.904 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-08T18:13:26.974Z,1557339206.974 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-08T18:13:26.976Z,1557339206.976 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-08T18:13:26.977Z,1557339206.977 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-08T18:13:26.997Z,1557339206.997 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-08T18:13:27.019Z,1557339207.019 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:13:27.025Z,1557339207.025 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-08T18:13:27.044Z,1557339207.044 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2019-05-08T18:13:27.049Z,1557339207.049 [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-05-08T18:13:27.059Z,1557339207.059 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-08T18:13:27.094Z,1557339207.094 [DUSBL_Hydroid](INFO): Powering up
2019-05-08T18:13:27.094Z,1557339207.094 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-08T18:13:27.161Z,1557339207.161 [Radio_Surface](INFO): Powering up
2019-05-08T18:13:27.208Z,1557339207.208 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:13:27.216Z,1557339207.216 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-08T18:13:27.217Z,1557339207.217 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:13:27.223Z,1557339207.223 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-08T18:13:27.223Z,1557339207.223 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:13:27.231Z,1557339207.231 [MassServo](DEBUG): Initializing MassServo.
2019-05-08T18:13:27.231Z,1557339207.231 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:13:27.239Z,1557339207.239 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-08T18:13:27.239Z,1557339207.239 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:13:27.247Z,1557339207.247 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-08T18:13:27.471Z,1557339207.471 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-05-08T18:13:27.473Z,1557339207.473 [Micromodem](INFO): Powering up
2019-05-08T18:13:27.473Z,1557339207.473 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-08T18:13:28.190Z,1557339208.190 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-08T18:13:28.191Z,1557339208.191 [RudderServo](FAULT): Rudder failed to initialize
2019-05-08T18:13:28.191Z,1557339208.191 [RudderServo] Communications Fault, FailCount= 1
2019-05-08T18:13:28.191Z,1557339208.191 [RudderServo](ERROR): Communications Fault
2019-05-08T18:13:28.302Z,1557339208.302 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-08T18:13:28.471Z,1557339208.471 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-08T18:13:28.471Z,1557339208.471 [RudderServo](INFO): Powering down
2019-05-08T18:13:29.146Z,1557339209.146 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:13:29.267Z,1557339209.267 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-08T18:13:29.272Z,1557339209.272 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-08T18:13:29.272Z,1557339209.272 [RudderServo] No Fault, FailCount= 1
2019-05-08T18:13:38.596Z,1557339218.596 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004885
2019-05-08T18:13:40.458Z,1557339220.458 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-08T18:13:45.280Z,1557339225.280 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-08T18:13:53.372Z,1557339233.372 [NAL9602](INFO): Powering up NAL9602
2019-05-08T18:14:04.268Z,1557339244.268 [NAL9602](INFO): NAL9602 initialized
2019-05-08T18:14:05.090Z,1557339245.090 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:14:08.357Z,1557339248.357 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-08T18:14:08.357Z,1557339248.357 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19050811214548,35.0, -0.,1448.9, 0
2019-05-08T18:14:11.192Z,1557339251.192 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-08T18:14:11.201Z,1557339251.201 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-08T18:14:21.707Z,1557339261.707 [NAL9602](INFO): SBD MO Status=0, MOMSN=3878, MT Status=0, MTMSN=0
2019-05-08T18:14:21.708Z,1557339261.708 [NAL9602](INFO): No messages in MT queue
2019-05-08T18:14:22.191Z,1557339262.191 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.023834
CHAN A1 (24V): -0.027199
CHAN A2 (12V): -0.006750
CHAN A3 (5V): -0.001839
CHAN B0 (3.3V): 0.000123
CHAN B1 (3.15aV): -0.000225
CHAN B2 (3.15bV): 0.000113
CHAN B3 (GND): 0.001733
OPEN: 0.005200
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-08T18:14:22.530Z,1557339262.530 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:14:25.758Z,1557339265.758 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:14:28.774Z,1557339268.774 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:14:29.162Z,1557339269.162 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181253.00,A,3648.15172,N,12147.19943,W,0.175,0.00,080519,,,A*78
2019-05-08T18:14:29.165Z,1557339269.165 [NAL9602](INFO): GPS fix at 20190508T181253: (36.802529, -121.786657)
2019-05-08T18:14:43.736Z,1557339283.736 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-08T18:14:43.736Z,1557339283.736 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19050811222048,35.0, -0.1, 8.9, 0
2019-05-08T18:14:59.800Z,1557339299.800 [CommandLine](IMPORTANT): got command show stack
2019-05-08T18:14:59.801Z,1557339299.801 [CommandLine](IMPORTANT): Behavior Stack:
2019-05-08T18:14:59.801Z,1557339299.801 [MissionManager](IMPORTANT): Mission loaded, but not running.
2019-05-08T18:15:01.577Z,1557339301.577 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-08T18:15:04.862Z,1557339304.862 [SBIT](IMPORTANT): SBIT PASSED
2019-05-08T18:15:04.931Z,1557339304.931 [CommandLine](IMPORTANT): got command configSet list
2019-05-08T18:15:04.931Z,1557339304.931 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-08T18:15:04.932Z,1557339304.932 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;
2019-05-08T18:15:04.932Z,1557339304.932 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;
2019-05-08T18:15:04.932Z,1557339304.932 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=20 count;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;
2019-05-08T18:15:04.933Z,1557339304.933 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;
2019-05-08T18:15:04.934Z,1557339304.934 [CommandLine](IMPORTANT): VerticalControl.massDefault=6 millimeter;
2019-05-08T18:15:05.237Z,1557339305.237 [MissionManager](IMPORTANT): Started mission Startup
2019-05-08T18:15:05.237Z,1557339305.237 [Startup] Running Loop=1
2019-05-08T18:15:05.237Z,1557339305.237 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-08T18:15:05.238Z,1557339305.238 [Startup:A.GoToSurface] Running Loop=1
2019-05-08T18:15:05.238Z,1557339305.238 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:15:05.238Z,1557339305.238 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:15:05.239Z,1557339305.239 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:15:05.239Z,1557339305.239 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:15:05.240Z,1557339305.240 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:15:05.240Z,1557339305.240 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:15:05.241Z,1557339305.241 [Startup:StartupSatComms] Running Loop=1
2019-05-08T18:15:05.241Z,1557339305.241 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-08T18:15:05.241Z,1557339305.241 [Startup:StartupSatComms:A] Running Loop=1
2019-05-08T18:15:05.646Z,1557339305.646 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-08T18:15:06.842Z,1557339306.842 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:15:07.231Z,1557339307.231 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181331.00,A,3648.14998,N,12147.19767,W,0.272,311.27,080519,,,A*7A
2019-05-08T18:15:07.233Z,1557339307.233 [NAL9602](INFO): GPS fix at 20190508T181331: (36.802500, -121.786628)
2019-05-08T18:15:07.277Z,1557339307.277 [Startup:StartupSatComms:A] Stopped
2019-05-08T18:15:07.277Z,1557339307.277 [Startup:StartupSatComms:B] Running Loop=1
2019-05-08T18:15:07.692Z,1557339307.692 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-08T18:15:09.092Z,1557339309.092 [CommandLine](IMPORTANT): got command show variable range
2019-05-08T18:15:09.095Z,1557339309.095 [CommandLine](IMPORTANT): acoustic_contact_range (unknown)
2019-05-08T18:15:09.310Z,1557339309.310 [CommandLine](IMPORTANT): BR_Ping1D.minrange (meter)
2019-05-08T18:15:09.311Z,1557339309.311 [CommandLine](IMPORTANT): BR_Ping1D.maxrange (meter)
2019-05-08T18:15:09.446Z,1557339309.446 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-05-08T18:15:09.455Z,1557339309.455 [CommandLine](IMPORTANT): Micromodem.range_request (count)
2019-05-08T18:15:09.456Z,1557339309.456 [CommandLine](IMPORTANT): Micromodem.range (meter)
2019-05-08T18:15:09.459Z,1557339309.459 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam1Range (meter)
2019-05-08T18:15:09.461Z,1557339309.461 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam2Range (meter)
2019-05-08T18:15:09.495Z,1557339309.495 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam3Range (meter)
2019-05-08T18:15:09.495Z,1557339309.495 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam4Range (meter)
2019-05-08T18:15:17.634Z,1557339317.634 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190507T223545/Courier0061.lzma
2019-05-08T18:15:18.440Z,1557339318.440 [DataOverHttps](INFO): Moved sent file to Logs/20190507T223545/Courier0061.lzma.bak
2019-05-08T18:15:18.441Z,1557339318.441 [DataOverHttps](INFO): SBD MOMSN=10975221
2019-05-08T18:15:23.768Z,1557339323.768 [CommandLine](IMPORTANT): got command report touch acoustic_contact_range
2019-05-08T18:15:26.855Z,1557339326.855 [CommandLine](IMPORTANT): got command show variable dusbl
2019-05-08T18:15:26.898Z,1557339326.898 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-05-08T18:15:26.898Z,1557339326.898 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-05-08T18:15:26.899Z,1557339326.899 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (second)
2019-05-08T18:15:26.899Z,1557339326.899 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-05-08T18:15:26.900Z,1557339326.900 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-05-08T18:15:26.900Z,1557339326.900 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-05-08T18:15:26.900Z,1557339326.900 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-05-08T18:15:26.901Z,1557339326.901 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-05-08T18:15:26.901Z,1557339326.901 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-05-08T18:15:26.901Z,1557339326.901 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-05-08T18:15:26.902Z,1557339326.902 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-05-08T18:15:26.902Z,1557339326.902 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-05-08T18:15:26.916Z,1557339326.916 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-05-08T18:15:26.916Z,1557339326.916 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-05-08T18:15:26.917Z,1557339326.917 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-05-08T18:15:26.921Z,1557339326.921 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (enum)
2019-05-08T18:15:26.921Z,1557339326.921 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-05-08T18:15:26.922Z,1557339326.922 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-05-08T18:15:26.961Z,1557339326.961 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-05-08T18:15:26.962Z,1557339326.962 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-05-08T18:15:26.962Z,1557339326.962 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-05-08T18:15:26.963Z,1557339326.963 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-05-08T18:15:26.963Z,1557339326.963 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-05-08T18:15:26.963Z,1557339326.963 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-05-08T18:15:26.964Z,1557339326.964 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_direction_vehicle_frame (none)
2019-05-08T18:15:26.964Z,1557339326.964 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_address (enum)
2019-05-08T18:15:34.022Z,1557339334.022 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190508T181315/Courier0000.lzma
2019-05-08T18:15:34.824Z,1557339334.824 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0000.lzma.bak
2019-05-08T18:15:34.824Z,1557339334.824 [DataOverHttps](INFO): SBD MOMSN=10975228
2019-05-08T18:15:47.419Z,1557339347.419 [DataOverHttps](INFO): Sending 494 bytes from file Logs/20190507T223545/Express0062.lzma
2019-05-08T18:15:48.224Z,1557339348.224 [DataOverHttps](INFO): Moved sent file to Logs/20190507T223545/Express0062.lzma.bak
2019-05-08T18:15:48.224Z,1557339348.224 [DataOverHttps](INFO): SBD MOMSN=10975232
2019-05-08T18:16:00.437Z,1557339360.437 [DataOverHttps](INFO): Sending 1349 bytes from file Logs/20190508T181315/Express0001.lzma
2019-05-08T18:16:01.240Z,1557339361.240 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0001.lzma.bak
2019-05-08T18:16:01.240Z,1557339361.240 [DataOverHttps](INFO): SBD MOMSN=10975249
2019-05-08T18:16:02.401Z,1557339362.401 [Startup:StartupSatComms:B] Stopped
2019-05-08T18:16:02.401Z,1557339362.401 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-08T18:16:02.401Z,1557339362.401 [Startup:StartupSatComms] Stopped
2019-05-08T18:16:02.401Z,1557339362.401 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-08T18:16:02.402Z,1557339362.402 [Startup](INFO): Completed Startup
2019-05-08T18:16:02.402Z,1557339362.402 [MissionManager](INFO): Startup is completed.
2019-05-08T18:16:02.406Z,1557339362.406 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-08T18:16:02.407Z,1557339362.407 [Startup] Stopped
2019-05-08T18:16:02.407Z,1557339362.407 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-08T18:16:02.407Z,1557339362.407 [Startup:A.GoToSurface] Stopped
2019-05-08T18:16:02.407Z,1557339362.407 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:16:02.745Z,1557339362.745 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:16:02.745Z,1557339362.745 [Default] Running Loop=1
2019-05-08T18:16:02.745Z,1557339362.745 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:16:02.745Z,1557339362.745 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:16:02.745Z,1557339362.745 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:16:02.746Z,1557339362.746 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:16:02.746Z,1557339362.746 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:16:02.746Z,1557339362.746 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:16:02.747Z,1557339362.747 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:16:02.747Z,1557339362.747 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:16:02.747Z,1557339362.747 [Default:A.Wait] Running Loop=1
2019-05-08T18:16:02.747Z,1557339362.747 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:16:16.081Z,1557339376.081 [Default:A.Wait](INFO): Done Waiting.
2019-05-08T18:16:16.081Z,1557339376.081 [Default:A.Wait] Stopped
2019-05-08T18:16:16.081Z,1557339376.081 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:16:16.491Z,1557339376.491 [Default:CheckIn] Running Loop=1
2019-05-08T18:16:16.491Z,1557339376.491 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:16:16.491Z,1557339376.491 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:16:16.899Z,1557339376.899 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-08T18:17:35.657Z,1557339455.657 [NAL9602](INFO): SBD MO Status=0, MOMSN=3879, MT Status=0, MTMSN=0
2019-05-08T18:17:35.657Z,1557339455.657 [NAL9602](INFO): No messages in MT queue
2019-05-08T18:17:36.458Z,1557339456.458 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:17:36.857Z,1557339456.857 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181601.00,A,3648.15005,N,12147.19787,W,0.097,66.06,080519,,,D*42
2019-05-08T18:17:36.859Z,1557339456.859 [NAL9602](INFO): GPS fix at 20190508T181601: (36.802501, -121.786631)
2019-05-08T18:17:36.883Z,1557339456.883 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:17:36.883Z,1557339456.883 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:17:37.306Z,1557339457.306 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-08T18:17:38.908Z,1557339458.908 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-05-08T18:17:43.478Z,1557339463.478 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190508T181315/Courier0004.lzma
2019-05-08T18:17:44.288Z,1557339464.288 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0004.lzma.bak
2019-05-08T18:17:44.288Z,1557339464.288 [DataOverHttps](INFO): SBD MOMSN=10975315
2019-05-08T18:17:55.171Z,1557339475.171 [CommandLine](IMPORTANT): got command report touch
2019-05-08T18:17:55.172Z,1557339475.172 [CommandLine](FAULT): Incomplete syntax. Try: help report
2019-05-08T18:17:57.675Z,1557339477.675 [DataOverHttps](INFO): Sending 992 bytes from file Logs/20190508T181315/Express0005.lzma
2019-05-08T18:17:58.480Z,1557339478.480 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0005.lzma.bak
2019-05-08T18:17:58.480Z,1557339478.480 [DataOverHttps](INFO): SBD MOMSN=10975318
2019-05-08T18:17:59.539Z,1557339479.539 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:17:59.539Z,1557339479.539 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:17:59.540Z,1557339479.540 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:18:09.580Z,1557339489.580 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-08T18:18:21.447Z,1557339501.447 [CommandLine](IMPORTANT): got command report
2019-05-08T18:18:21.447Z,1557339501.447 [Reporter](INFO): acoustic_contact_range reporting when touched
2019-05-08T18:18:21.449Z,1557339501.449 [CommandLine](IMPORTANT): got command failComponent
2019-05-08T18:18:21.449Z,1557339501.449 [CommandLine](IMPORTANT): Failed components:
2019-05-08T18:18:21.450Z,1557339501.450 [CommandLine](IMPORTANT): No failed Components.
2019-05-08T18:18:21.452Z,1557339501.452 [CommandLine](IMPORTANT): got command failComponent
2019-05-08T18:18:21.452Z,1557339501.452 [CommandLine](IMPORTANT): Failed components:
2019-05-08T18:18:21.452Z,1557339501.452 [CommandLine](IMPORTANT): No failed Components.
2019-05-08T18:18:24.721Z,1557339504.721 [CommandLine](IMPORTANT): got command failComponent
2019-05-08T18:18:24.721Z,1557339504.721 [CommandLine](IMPORTANT): Failed components:
2019-05-08T18:18:24.721Z,1557339504.721 [CommandLine](IMPORTANT): No failed Components.
2019-05-08T18:20:51.224Z,1557339651.224 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-05-08T18:20:51.228Z,1557339651.228 [BPC1](INFO): Received data from all battery sticks.
2019-05-08T18:22:18.899Z,1557339738.899 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-05-08T18:23:00.117Z,1557339780.117 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-08T18:23:00.117Z,1557339780.117 [Default:CheckIn:C.Wait] Stopped
2019-05-08T18:23:00.117Z,1557339780.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:23:00.117Z,1557339780.117 [Default:CheckIn:D] Running Loop=1
2019-05-08T18:23:00.520Z,1557339780.520 [Default:CheckIn:D] Stopped
2019-05-08T18:23:00.521Z,1557339780.521 [Default:CheckIn:E] Running Loop=1
2019-05-08T18:23:00.924Z,1557339780.924 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.962920 min
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn:E] Stopped
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn] Stopped
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn](INFO): Running loop #2
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn] Running Loop=2
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:23:00.925Z,1557339780.925 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:23:02.514Z,1557339782.514 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:23:02.911Z,1557339782.911 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182128.00,A,3648.14945,N,12147.19768,W,0.272,66.06,080519,,,D*49
2019-05-08T18:23:02.913Z,1557339782.913 [NAL9602](INFO): GPS fix at 20190508T182128: (36.802491, -121.786628)
2019-05-08T18:23:02.936Z,1557339782.936 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:23:02.936Z,1557339782.936 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:23:05.085Z,1557339785.085 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-05-08T18:23:08.982Z,1557339788.982 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20190508T181315/Courier0007.lzma
2019-05-08T18:23:09.788Z,1557339789.788 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0007.lzma.bak
2019-05-08T18:23:09.788Z,1557339789.788 [DataOverHttps](INFO): SBD MOMSN=10975426
2019-05-08T18:23:18.411Z,1557339798.411 [NAL9602](INFO): SBD MO Status=0, MOMSN=3880, MT Status=0, MTMSN=0
2019-05-08T18:23:18.411Z,1557339798.411 [NAL9602](INFO): No messages in MT queue
2019-05-08T18:23:25.612Z,1557339805.612 [CommandLine](IMPORTANT): got command failComponent
2019-05-08T18:23:25.612Z,1557339805.612 [CommandLine](IMPORTANT): Failed components:
2019-05-08T18:23:25.612Z,1557339805.612 [CommandLine](IMPORTANT): No failed Components.
2019-05-08T18:23:26.367Z,1557339806.367 [DataOverHttps](INFO): Sending 866 bytes from file Logs/20190508T181315/Express0008.lzma
2019-05-08T18:23:27.164Z,1557339807.164 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0008.lzma.bak
2019-05-08T18:23:27.164Z,1557339807.164 [DataOverHttps](INFO): SBD MOMSN=10975429
2019-05-08T18:23:27.973Z,1557339807.973 [CommandLine](IMPORTANT): got command report
2019-05-08T18:23:27.973Z,1557339807.973 [Reporter](INFO): acoustic_contact_range reporting when touched
2019-05-08T18:23:28.570Z,1557339808.570 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:23:28.570Z,1557339808.570 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:23:28.570Z,1557339808.570 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:23:31.892Z,1557339811.892 [CommandLine](IMPORTANT): got command show variable dusbl
2019-05-08T18:23:31.971Z,1557339811.971 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-05-08T18:23:31.971Z,1557339811.971 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-05-08T18:23:31.971Z,1557339811.971 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (second)
2019-05-08T18:23:31.972Z,1557339811.972 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-05-08T18:23:31.972Z,1557339811.972 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-05-08T18:23:31.973Z,1557339811.973 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-05-08T18:23:31.973Z,1557339811.973 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-05-08T18:23:31.973Z,1557339811.973 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-05-08T18:23:31.974Z,1557339811.974 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-05-08T18:23:31.974Z,1557339811.974 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-05-08T18:23:31.979Z,1557339811.979 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-05-08T18:23:31.979Z,1557339811.979 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-05-08T18:23:32.004Z,1557339812.004 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-05-08T18:23:32.005Z,1557339812.005 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-05-08T18:23:32.005Z,1557339812.005 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-05-08T18:23:32.013Z,1557339812.013 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (enum)
2019-05-08T18:23:32.014Z,1557339812.014 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-05-08T18:23:32.018Z,1557339812.018 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-05-08T18:23:32.019Z,1557339812.019 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-05-08T18:23:32.019Z,1557339812.019 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-05-08T18:23:32.020Z,1557339812.020 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-05-08T18:23:32.020Z,1557339812.020 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-05-08T18:23:32.021Z,1557339812.021 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-05-08T18:23:32.021Z,1557339812.021 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-05-08T18:23:32.021Z,1557339812.021 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_direction_vehicle_frame (none)
2019-05-08T18:23:32.022Z,1557339812.022 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_address (enum)
2019-05-08T18:23:40.805Z,1557339820.805 [CommandLine](IMPORTANT): got command report touch
2019-05-08T18:23:40.805Z,1557339820.805 [CommandLine](FAULT): Incomplete syntax. Try: help report
2019-05-08T18:23:48.095Z,1557339828.095 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.xAngle
2019-05-08T18:23:49.120Z,1557339829.120 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-08T18:23:57.493Z,1557339837.493 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:23:57.493Z,1557339837.493 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:23:57.526Z,1557339837.526 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-08T18:23:57.530Z,1557339837.530 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-08T18:23:57.557Z,1557339837.557 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-08T18:23:57.574Z,1557339837.574 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-08T18:23:57.578Z,1557339837.578 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-08T18:23:57.579Z,1557339837.579 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-08T18:23:57.633Z,1557339837.633 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-08T18:23:57.658Z,1557339837.658 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:23:57.678Z,1557339837.678 [MissionManager](DEBUG):
This mission is requests a DUSBL arming.
How long to let the mission run.
90
Number of pings to requst.
10
Transponder Address.
2
Number of pings requested each time.
1
Automatically set to true if the DUSBL is enabled. Set to false to disable
reading from the DUSBL.
0
10
2019-05-08T18:23:57.681Z,1557339837.681 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:23:58.033Z,1557339838.033 [Default] Stopped
2019-05-08T18:23:58.033Z,1557339838.033 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:23:58.033Z,1557339838.033 [Default:B.GoToSurface] Stopped
2019-05-08T18:23:58.033Z,1557339838.033 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:23:58.033Z,1557339838.033 [Default:CheckIn] Stopped
2019-05-08T18:23:58.034Z,1557339838.034 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:23:58.034Z,1557339838.034 [Default:CheckIn:C.Wait] Stopped
2019-05-08T18:23:58.034Z,1557339838.034 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:23:58.034Z,1557339838.034 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-08T18:23:58.034Z,1557339838.034 [DUSBL] Running Loop=1
2019-05-08T18:23:58.034Z,1557339838.034 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:C] Running Loop=1
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:RequestRepeater] Running Loop=1
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:23:58.035Z,1557339838.035 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:23:58.036Z,1557339838.036 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:23:58.036Z,1557339838.036 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:23:58.036Z,1557339838.036 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:23:58.036Z,1557339838.036 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:23:58.037Z,1557339838.037 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-08T18:23:58.038Z,1557339838.038 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-08T18:23:58.038Z,1557339838.038 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:23:58.038Z,1557339838.038 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:24:03.260Z,1557339843.260 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:24:04.871Z,1557339844.871 [DUSBL_Hydroid](ERROR): unknown deviceResponse_: !U1,R,080,000,00E1E,186
2019-05-08T18:24:08.131Z,1557339848.131 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:24:08.131Z,1557339848.131 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:24:08.131Z,1557339848.131 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater] Running Loop=2
2019-05-08T18:24:08.132Z,1557339848.132 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:24:08.133Z,1557339848.133 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:24:08.133Z,1557339848.133 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:24:08.133Z,1557339848.133 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:24:08.133Z,1557339848.133 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:24:11.456Z,1557339851.456 [Reporter](INFO): acoustic_contact_range 176.819992 m
2019-05-08T18:24:11.457Z,1557339851.457 [Reporter](INFO): DUSBL_Hydroid.xAngle -8.850000 arcdeg
2019-05-08T18:24:18.645Z,1557339858.645 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:24:18.645Z,1557339858.645 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:24:18.645Z,1557339858.645 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:24:18.646Z,1557339858.646 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:24:18.646Z,1557339858.646 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:24:18.646Z,1557339858.646 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater] Running Loop=3
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:24:18.647Z,1557339858.647 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:24:29.149Z,1557339869.149 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:24:29.149Z,1557339869.149 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:24:29.149Z,1557339869.149 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:24:29.150Z,1557339869.150 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:24:29.150Z,1557339869.150 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:24:29.150Z,1557339869.150 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:24:29.150Z,1557339869.150 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater] Running Loop=4
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:24:29.151Z,1557339869.151 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:24:29.516Z,1557339869.516 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:24:31.140Z,1557339871.140 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:24:32.748Z,1557339872.748 [DUSBL_Hydroid](ERROR): unknown deviceResponse_: !U1,R,04BP
00,00000,187,80,81,1D,FF
2019-05-08T18:24:39.662Z,1557339879.662 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:24:39.662Z,1557339879.662 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:24:39.662Z,1557339879.662 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:24:39.667Z,1557339879.667 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:24:39.667Z,1557339879.667 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:24:39.667Z,1557339879.667 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:24:39.667Z,1557339879.667 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:24:39.667Z,1557339879.667 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:24:39.667Z,1557339879.667 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-08T18:24:39.668Z,1557339879.668 [DUSBL:RequestRepeater] Running Loop=5
2019-05-08T18:24:39.668Z,1557339879.668 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:24:39.668Z,1557339879.668 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:24:39.668Z,1557339879.668 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:24:39.668Z,1557339879.668 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:24:39.668Z,1557339879.668 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:24:41.232Z,1557339881.232 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:24:50.145Z,1557339890.145 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:24:50.146Z,1557339890.146 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:24:50.146Z,1557339890.146 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:24:50.146Z,1557339890.146 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater] Running Loop=6
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:24:50.147Z,1557339890.147 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:24:57.392Z,1557339897.392 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:25:00.661Z,1557339900.661 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:25:00.661Z,1557339900.661 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:25:00.662Z,1557339900.662 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:25:00.662Z,1557339900.662 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:25:00.662Z,1557339900.662 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater] Running Loop=7
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:25:00.663Z,1557339900.663 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:25:01.842Z,1557339901.842 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:25:03.517Z,1557339903.517 [Reporter](INFO): acoustic_contact_range 176.639999 m
2019-05-08T18:25:03.518Z,1557339903.518 [Reporter](INFO): DUSBL_Hydroid.xAngle -4.800000 arcdeg
2019-05-08T18:25:07.124Z,1557339907.124 [Reporter](INFO): acoustic_contact_range 176.700012 m
2019-05-08T18:25:07.125Z,1557339907.125 [Reporter](INFO): DUSBL_Hydroid.xAngle -3.150000 arcdeg
2019-05-08T18:25:10.763Z,1557339910.763 [Reporter](INFO): acoustic_contact_range 179.700012 m
2019-05-08T18:25:10.764Z,1557339910.764 [Reporter](INFO): DUSBL_Hydroid.xAngle -3.150000 arcdeg
2019-05-08T18:25:11.156Z,1557339911.156 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:25:11.156Z,1557339911.156 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:25:11.156Z,1557339911.156 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:25:11.156Z,1557339911.156 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:25:11.156Z,1557339911.156 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:25:11.156Z,1557339911.156 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater] Running Loop=8
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:25:11.157Z,1557339911.157 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:25:16.788Z,1557339916.788 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:25:18.448Z,1557339918.448 [Reporter](INFO): acoustic_contact_range 177.000015 m
2019-05-08T18:25:18.449Z,1557339918.449 [Reporter](INFO): DUSBL_Hydroid.xAngle -13.650000 arcdeg
2019-05-08T18:25:21.709Z,1557339921.709 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:25:21.709Z,1557339921.709 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:25:21.709Z,1557339921.709 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:25:21.710Z,1557339921.710 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:25:21.710Z,1557339921.710 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:25:21.710Z,1557339921.710 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:25:21.718Z,1557339921.718 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:25:21.718Z,1557339921.718 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:25:21.719Z,1557339921.719 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-08T18:25:21.719Z,1557339921.719 [DUSBL:RequestRepeater] Running Loop=9
2019-05-08T18:25:21.719Z,1557339921.719 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:25:21.719Z,1557339921.719 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:25:21.719Z,1557339921.719 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:25:21.719Z,1557339921.719 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:25:21.719Z,1557339921.719 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:25:22.195Z,1557339922.195 [Reporter](INFO): acoustic_contact_range 179.519989 m
2019-05-08T18:25:22.196Z,1557339922.196 [Reporter](INFO): DUSBL_Hydroid.xAngle -9.300000 arcdeg
2019-05-08T18:25:32.181Z,1557339932.181 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:25:32.181Z,1557339932.181 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:25:32.181Z,1557339932.181 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:25:32.182Z,1557339932.182 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:25:32.186Z,1557339932.186 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:25:32.186Z,1557339932.186 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:25:32.186Z,1557339932.186 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater] Running Loop=10
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:25:32.187Z,1557339932.187 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:25:34.160Z,1557339934.160 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:25:38.196Z,1557339938.196 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:25:39.855Z,1557339939.855 [Reporter](INFO): acoustic_contact_range 179.279999 m
2019-05-08T18:25:39.856Z,1557339939.856 [Reporter](INFO): DUSBL_Hydroid.xAngle -5.800000 arcdeg
2019-05-08T18:25:42.697Z,1557339942.697 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:25:42.697Z,1557339942.697 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:25:42.697Z,1557339942.697 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:25:42.698Z,1557339942.698 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:25:42.698Z,1557339942.698 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:25:42.714Z,1557339942.714 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:25:42.714Z,1557339942.714 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:25:42.715Z,1557339942.715 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:25:42.715Z,1557339942.715 [DUSBL](INFO): Completed DUSBL
2019-05-08T18:25:42.715Z,1557339942.715 [MissionManager](INFO): DUSBL is completed.
2019-05-08T18:25:42.716Z,1557339942.716 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-08T18:25:42.716Z,1557339942.716 [DUSBL] Stopped
2019-05-08T18:25:42.716Z,1557339942.716 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-08T18:25:42.716Z,1557339942.716 [DUSBL:A.Pitch] Stopped
2019-05-08T18:25:42.716Z,1557339942.716 [DUSBL:B.SetSpeed] Stopped
2019-05-08T18:25:42.716Z,1557339942.716 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-08T18:25:42.716Z,1557339942.716 [DUSBL:C] Stopped
2019-05-08T18:25:43.085Z,1557339943.085 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:25:43.085Z,1557339943.085 [Default] Running Loop=1
2019-05-08T18:25:43.085Z,1557339943.085 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:25:43.085Z,1557339943.085 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:25:43.085Z,1557339943.085 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:25:43.086Z,1557339943.086 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:25:43.086Z,1557339943.086 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:25:43.087Z,1557339943.087 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:25:43.087Z,1557339943.087 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:25:43.087Z,1557339943.087 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:25:43.088Z,1557339943.088 [Default:A.Wait] Running Loop=1
2019-05-08T18:25:43.088Z,1557339943.088 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:25:48.045Z,1557339948.045 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:25:48.045Z,1557339948.045 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:25:48.113Z,1557339948.113 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-08T18:25:48.115Z,1557339948.115 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-08T18:25:48.117Z,1557339948.117 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-08T18:25:48.120Z,1557339948.120 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-08T18:25:48.122Z,1557339948.122 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-08T18:25:48.152Z,1557339948.152 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-08T18:25:48.168Z,1557339948.168 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-08T18:25:48.197Z,1557339948.197 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:25:48.201Z,1557339948.201 [MissionManager](DEBUG):
This mission is requests a DUSBL arming.
How long to let the mission run.
90
Number of pings to requst.
10
Transponder Address.
2
Number of pings requested each time.
1
Automatically set to true if the DUSBL is enabled. Set to false to disable
reading from the DUSBL.
0
10
2019-05-08T18:25:48.211Z,1557339948.211 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:25:48.321Z,1557339948.321 [Default] Stopped
2019-05-08T18:25:48.321Z,1557339948.321 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:25:48.321Z,1557339948.321 [Default:A.Wait] Stopped
2019-05-08T18:25:48.322Z,1557339948.322 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:25:48.322Z,1557339948.322 [Default:B.GoToSurface] Stopped
2019-05-08T18:25:48.322Z,1557339948.322 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:25:48.322Z,1557339948.322 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-08T18:25:48.322Z,1557339948.322 [DUSBL] Running Loop=1
2019-05-08T18:25:48.322Z,1557339948.322 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-08T18:25:48.323Z,1557339948.323 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:25:48.323Z,1557339948.323 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-08T18:25:48.323Z,1557339948.323 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:25:48.323Z,1557339948.323 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-08T18:25:48.323Z,1557339948.323 [DUSBL:C] Running Loop=1
2019-05-08T18:25:48.323Z,1557339948.323 [DUSBL:RequestRepeater] Running Loop=1
2019-05-08T18:25:48.323Z,1557339948.323 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:25:48.324Z,1557339948.324 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:25:48.324Z,1557339948.324 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:25:48.324Z,1557339948.324 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:25:48.324Z,1557339948.324 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:25:48.324Z,1557339948.324 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:25:48.324Z,1557339948.324 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:25:48.325Z,1557339948.325 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-08T18:25:48.325Z,1557339948.325 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-08T18:25:48.326Z,1557339948.326 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:25:48.326Z,1557339948.326 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:25:51.124Z,1557339951.124 [DUSBL_Hydroid](ERROR): unknown deviceResponse_: !U1,R,034,01,P
0E1D,186,80,80,1D,FF
2019-05-08T18:25:58.508Z,1557339958.508 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:25:58.508Z,1557339958.508 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:25:58.508Z,1557339958.508 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:25:58.509Z,1557339958.509 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:25:58.509Z,1557339958.509 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:25:58.509Z,1557339958.509 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:25:58.509Z,1557339958.509 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:25:58.509Z,1557339958.509 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:25:58.509Z,1557339958.509 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-08T18:25:58.510Z,1557339958.510 [DUSBL:RequestRepeater] Running Loop=2
2019-05-08T18:25:58.510Z,1557339958.510 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:25:58.510Z,1557339958.510 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:25:58.510Z,1557339958.510 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:25:58.510Z,1557339958.510 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:25:58.510Z,1557339958.510 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:25:59.608Z,1557339959.608 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:01.279Z,1557339961.279 [Reporter](INFO): acoustic_contact_range 181.559998 m
2019-05-08T18:26:01.280Z,1557339961.280 [Reporter](INFO): DUSBL_Hydroid.xAngle -5.150000 arcdeg
2019-05-08T18:26:05.264Z,1557339965.264 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:26:08.958Z,1557339968.958 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:26:08.958Z,1557339968.958 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:26:08.958Z,1557339968.958 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:26:08.959Z,1557339968.959 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:26:08.959Z,1557339968.959 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:26:08.959Z,1557339968.959 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:26:08.959Z,1557339968.959 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:26:08.959Z,1557339968.959 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:26:08.959Z,1557339968.959 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-08T18:26:08.959Z,1557339968.959 [DUSBL:RequestRepeater] Running Loop=3
2019-05-08T18:26:08.960Z,1557339968.960 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:26:08.960Z,1557339968.960 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:26:08.960Z,1557339968.960 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:26:08.960Z,1557339968.960 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:26:08.960Z,1557339968.960 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:26:09.319Z,1557339969.319 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:13.752Z,1557339973.751 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:17.792Z,1557339977.792 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:19.445Z,1557339979.445 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:26:19.445Z,1557339979.445 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:26:19.445Z,1557339979.445 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:26:19.446Z,1557339979.446 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:26:19.446Z,1557339979.446 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:26:19.446Z,1557339979.446 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:26:19.446Z,1557339979.446 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater] Running Loop=4
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:26:19.447Z,1557339979.447 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:26:22.236Z,1557339982.236 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:23.454Z,1557339983.454 [Micromodem](ERROR): Response from modem unexpected: $CACST,6,1,20190508182621.441697,06,377,19,0095,0150,246,00,00,01,00,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,197,0.05,-999,9760,4000*5C
2019-05-08T18:26:29.935Z,1557339989.935 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:26:29.935Z,1557339989.935 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:26:29.935Z,1557339989.935 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:26:29.936Z,1557339989.936 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:26:29.936Z,1557339989.936 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:26:29.936Z,1557339989.936 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:26:29.936Z,1557339989.936 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:26:29.936Z,1557339989.936 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:26:29.936Z,1557339989.936 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-08T18:26:29.936Z,1557339989.936 [DUSBL:RequestRepeater] Running Loop=5
2019-05-08T18:26:29.937Z,1557339989.937 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:26:29.937Z,1557339989.937 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:26:29.937Z,1557339989.937 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:26:29.937Z,1557339989.937 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:26:29.937Z,1557339989.937 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:26:32.367Z,1557339992.367 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:36.380Z,1557339996.380 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:38.055Z,1557339998.055 [Reporter](INFO): acoustic_contact_range 182.699997 m
2019-05-08T18:26:38.056Z,1557339998.056 [Reporter](INFO): DUSBL_Hydroid.xAngle -4.550000 arcdeg
2019-05-08T18:26:40.453Z,1557340000.453 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:26:40.453Z,1557340000.453 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:26:40.453Z,1557340000.453 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:26:40.454Z,1557340000.454 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:26:40.454Z,1557340000.454 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater] Running Loop=6
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:26:40.455Z,1557340000.455 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:26:44.071Z,1557340004.071 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:45.669Z,1557340005.669 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:26:49.708Z,1557340009.708 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:50.969Z,1557340010.969 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:26:50.969Z,1557340010.969 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:26:50.969Z,1557340010.969 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:26:50.970Z,1557340010.970 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:26:50.970Z,1557340010.970 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:26:50.970Z,1557340010.970 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater] Running Loop=7
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:26:50.971Z,1557340010.971 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:26:53.744Z,1557340013.744 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:26:57.788Z,1557340017.788 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:27:01.457Z,1557340021.457 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:27:01.457Z,1557340021.457 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:27:01.457Z,1557340021.457 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:27:01.458Z,1557340021.458 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:27:01.458Z,1557340021.458 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:27:01.458Z,1557340021.458 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:27:01.458Z,1557340021.458 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:27:01.458Z,1557340021.458 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:27:01.459Z,1557340021.459 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-08T18:27:01.459Z,1557340021.459 [DUSBL:RequestRepeater] Running Loop=8
2019-05-08T18:27:01.459Z,1557340021.459 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:27:01.459Z,1557340021.459 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:27:01.459Z,1557340021.459 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:27:01.459Z,1557340021.459 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:27:01.459Z,1557340021.459 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:27:01.824Z,1557340021.824 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:27:03.448Z,1557340023.448 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:27:07.480Z,1557340027.480 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:27:08.725Z,1557340028.725 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-08T18:27:08.725Z,1557340028.725 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19050811344548,35.0, -0.1, 0.0,144
2019-05-08T18:27:11.954Z,1557340031.954 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:27:11.954Z,1557340031.954 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:27:11.954Z,1557340031.954 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater] Running Loop=9
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:27:11.955Z,1557340031.955 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:27:11.956Z,1557340031.956 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:27:11.956Z,1557340031.956 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:27:15.196Z,1557340035.196 [Reporter](INFO): acoustic_contact_range 183.480011 m
2019-05-08T18:27:15.197Z,1557340035.197 [Reporter](INFO): DUSBL_Hydroid.xAngle -6.500000 arcdeg
2019-05-08T18:27:16.462Z,1557340036.462 [CommandLine](IMPORTANT): got command show stack
2019-05-08T18:27:16.462Z,1557340036.462 [CommandLine](IMPORTANT): Behavior Stack:
2019-05-08T18:27:16.462Z,1557340036.462 [DUSBL](IMPORTANT): Priority 0: DUSBL:A.Pitch
2019-05-08T18:27:16.463Z,1557340036.463 [DUSBL](IMPORTANT): Priority 1: DUSBL:B.SetSpeed
2019-05-08T18:27:16.463Z,1557340036.463 [DUSBL](IMPORTANT): Priority 2: DUSBL:C
2019-05-08T18:27:16.463Z,1557340036.463 [DUSBL:RequestRepeater](IMPORTANT): Priority 3: DUSBL:RequestRepeater:A
2019-05-08T18:27:16.464Z,1557340036.464 [DUSBL:RequestRepeater](IMPORTANT): Priority 4: DUSBL:RequestRepeater:B
2019-05-08T18:27:16.464Z,1557340036.464 [DUSBL:RequestRepeater](IMPORTANT): Priority 5: DUSBL:RequestRepeater:C.Wait
2019-05-08T18:27:18.796Z,1557340038.796 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:27:20.828Z,1557340040.828 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:27:22.465Z,1557340042.465 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:27:22.465Z,1557340042.465 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:27:22.465Z,1557340042.465 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:27:22.471Z,1557340042.471 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:27:22.471Z,1557340042.471 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater] Running Loop=10
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:27:22.472Z,1557340042.472 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:27:24.856Z,1557340044.856 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:27:26.556Z,1557340046.556 [Reporter](INFO): acoustic_contact_range 180.360001 m
2019-05-08T18:27:26.557Z,1557340046.557 [Reporter](INFO): DUSBL_Hydroid.xAngle -11.450000 arcdeg
2019-05-08T18:27:30.180Z,1557340050.180 [Reporter](INFO): acoustic_contact_range 177.059998 m
2019-05-08T18:27:30.180Z,1557340050.180 [Reporter](INFO): DUSBL_Hydroid.xAngle -5.150000 arcdeg
2019-05-08T18:27:33.024Z,1557340053.024 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:27:33.024Z,1557340053.024 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:27:33.024Z,1557340053.024 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:27:33.024Z,1557340053.024 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:27:33.024Z,1557340053.024 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:27:33.025Z,1557340053.025 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:27:33.025Z,1557340053.025 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:27:33.025Z,1557340053.025 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:27:33.025Z,1557340053.025 [DUSBL](INFO): Completed DUSBL
2019-05-08T18:27:33.025Z,1557340053.025 [MissionManager](INFO): DUSBL is completed.
2019-05-08T18:27:33.026Z,1557340053.026 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-08T18:27:33.026Z,1557340053.026 [DUSBL] Stopped
2019-05-08T18:27:33.026Z,1557340053.026 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-08T18:27:33.026Z,1557340053.026 [DUSBL:A.Pitch] Stopped
2019-05-08T18:27:33.026Z,1557340053.026 [DUSBL:B.SetSpeed] Stopped
2019-05-08T18:27:33.026Z,1557340053.026 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-08T18:27:33.030Z,1557340053.030 [DUSBL:C] Stopped
2019-05-08T18:27:33.412Z,1557340053.412 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:27:33.413Z,1557340053.413 [Default] Running Loop=1
2019-05-08T18:27:33.413Z,1557340053.413 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:27:33.413Z,1557340053.413 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:27:33.413Z,1557340053.413 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:27:33.413Z,1557340053.413 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:27:33.413Z,1557340053.413 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:27:33.414Z,1557340053.414 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:27:33.414Z,1557340053.414 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:27:33.415Z,1557340053.415 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:27:33.416Z,1557340053.416 [Default:A.Wait] Running Loop=1
2019-05-08T18:27:33.416Z,1557340053.416 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:27:38.124Z,1557340058.124 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:27:38.125Z,1557340058.125 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:27:38.170Z,1557340058.170 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-08T18:27:38.193Z,1557340058.193 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-08T18:27:38.204Z,1557340058.204 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-08T18:27:38.212Z,1557340058.212 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-08T18:27:38.218Z,1557340058.218 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-08T18:27:38.219Z,1557340058.219 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-08T18:27:38.228Z,1557340058.228 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-08T18:27:38.245Z,1557340058.245 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:27:38.265Z,1557340058.265 [MissionManager](DEBUG):
This mission is requests a DUSBL arming.
How long to let the mission run.
90
Number of pings to requst.
10
Transponder Address.
2
Number of pings requested each time.
1
Automatically set to true if the DUSBL is enabled. Set to false to disable
reading from the DUSBL.
0
10
2019-05-08T18:27:38.271Z,1557340058.271 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:27:38.624Z,1557340058.624 [Default] Stopped
2019-05-08T18:27:38.624Z,1557340058.624 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:27:38.624Z,1557340058.624 [Default:A.Wait] Stopped
2019-05-08T18:27:38.624Z,1557340058.624 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:27:38.624Z,1557340058.624 [Default:B.GoToSurface] Stopped
2019-05-08T18:27:38.624Z,1557340058.624 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:27:38.625Z,1557340058.625 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-08T18:27:38.625Z,1557340058.625 [DUSBL] Running Loop=1
2019-05-08T18:27:38.625Z,1557340058.625 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-08T18:27:38.625Z,1557340058.625 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:27:38.625Z,1557340058.625 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-08T18:27:38.625Z,1557340058.625 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:27:38.625Z,1557340058.625 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-08T18:27:38.626Z,1557340058.626 [DUSBL:C] Running Loop=1
2019-05-08T18:27:38.626Z,1557340058.626 [DUSBL:RequestRepeater] Running Loop=1
2019-05-08T18:27:38.626Z,1557340058.626 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:27:38.626Z,1557340058.626 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:27:38.626Z,1557340058.626 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:27:38.626Z,1557340058.626 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:27:38.627Z,1557340058.627 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:27:38.627Z,1557340058.627 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:27:38.627Z,1557340058.627 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:27:38.628Z,1557340058.628 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-08T18:27:38.628Z,1557340058.628 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-08T18:27:38.628Z,1557340058.628 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:27:38.629Z,1557340058.629 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:27:41.472Z,1557340061.472 [Reporter](INFO): acoustic_contact_range 177.059998 m
2019-05-08T18:27:41.473Z,1557340061.473 [Reporter](INFO): DUSBL_Hydroid.xAngle -4.950000 arcdeg
2019-05-08T18:27:47.480Z,1557340067.480 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:27:48.744Z,1557340068.744 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:27:48.744Z,1557340068.744 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:27:48.744Z,1557340068.744 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:27:48.745Z,1557340068.745 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:27:48.745Z,1557340068.745 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:27:48.745Z,1557340068.745 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:27:48.745Z,1557340068.745 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:27:48.745Z,1557340068.745 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:27:48.746Z,1557340068.746 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-08T18:27:48.746Z,1557340068.746 [DUSBL:RequestRepeater] Running Loop=2
2019-05-08T18:27:48.746Z,1557340068.746 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:27:48.746Z,1557340068.746 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:27:48.746Z,1557340068.746 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:27:48.746Z,1557340068.746 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:27:48.746Z,1557340068.746 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:27:51.518Z,1557340071.518 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:27:55.971Z,1557340075.971 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:27:59.225Z,1557340079.225 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:27:59.225Z,1557340079.225 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:27:59.225Z,1557340079.225 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:27:59.226Z,1557340079.226 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater] Running Loop=3
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:27:59.227Z,1557340079.227 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:28:00.008Z,1557340080.008 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:01.669Z,1557340081.669 [Reporter](INFO): acoustic_contact_range 177.059998 m
2019-05-08T18:28:01.670Z,1557340081.670 [Reporter](INFO): DUSBL_Hydroid.xAngle -5.700000 arcdeg
2019-05-08T18:28:07.687Z,1557340087.687 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:09.737Z,1557340089.737 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:28:09.737Z,1557340089.737 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:28:09.737Z,1557340089.737 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:28:09.738Z,1557340089.738 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:28:09.738Z,1557340089.738 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:28:09.754Z,1557340089.754 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:28:09.754Z,1557340089.754 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:28:09.754Z,1557340089.754 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:28:09.755Z,1557340089.755 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-08T18:28:09.755Z,1557340089.755 [DUSBL:RequestRepeater] Running Loop=4
2019-05-08T18:28:09.755Z,1557340089.755 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:28:09.755Z,1557340089.755 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:28:09.755Z,1557340089.755 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:28:09.755Z,1557340089.755 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:28:09.755Z,1557340089.755 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:28:11.721Z,1557340091.721 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:15.367Z,1557340095.367 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:16.972Z,1557340096.972 [DUSBL_Hydroid](ERROR): unknown deviceResponse_: !U1,R,07A,
!U1,P
F8,186,80,81,14,FF
2019-05-08T18:28:20.229Z,1557340100.229 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:28:20.229Z,1557340100.229 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:28:20.230Z,1557340100.230 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:28:20.230Z,1557340100.230 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:28:20.230Z,1557340100.230 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater] Running Loop=5
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:28:20.231Z,1557340100.231 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:28:25.463Z,1557340105.463 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:29.500Z,1557340109.500 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:30.757Z,1557340110.757 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:28:30.757Z,1557340110.757 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:28:30.757Z,1557340110.757 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:28:30.758Z,1557340110.758 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:28:30.758Z,1557340110.758 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:28:30.758Z,1557340110.758 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:28:30.758Z,1557340110.758 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater] Running Loop=6
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:28:30.759Z,1557340110.759 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:28:33.539Z,1557340113.539 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:37.576Z,1557340117.576 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:41.241Z,1557340121.241 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:28:41.241Z,1557340121.241 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:28:41.241Z,1557340121.241 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:28:41.242Z,1557340121.242 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:28:41.242Z,1557340121.242 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater] Running Loop=7
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:28:41.243Z,1557340121.243 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:28:41.624Z,1557340121.624 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:28:49.292Z,1557340129.292 [DUSBL_Hydroid](ERROR): unknown deviceResponse_: !U1,R,050,0,61
,P
8,186,80,81,14,FF
2019-05-08T18:28:51.750Z,1557340131.750 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:28:51.750Z,1557340131.750 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:28:51.750Z,1557340131.750 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater] Running Loop=8
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:28:51.751Z,1557340131.751 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:28:51.752Z,1557340131.752 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:28:51.752Z,1557340131.752 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:28:51.752Z,1557340131.752 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:28:55.372Z,1557340135.372 [DUSBL_Hydroid](ERROR): unknown deviceResponse_: !U1,R,044,000,00F
8,186,80,81,14,FF
2019-05-08T18:29:02.258Z,1557340142.258 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:29:02.258Z,1557340142.258 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:29:02.258Z,1557340142.258 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:29:02.259Z,1557340142.259 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:29:02.259Z,1557340142.259 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:29:02.259Z,1557340142.259 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:29:02.259Z,1557340142.259 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:29:02.259Z,1557340142.259 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:29:02.260Z,1557340142.260 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-08T18:29:02.260Z,1557340142.260 [DUSBL:RequestRepeater] Running Loop=9
2019-05-08T18:29:02.260Z,1557340142.260 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:29:02.260Z,1557340142.260 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:29:02.260Z,1557340142.260 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:29:02.260Z,1557340142.260 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:29:02.260Z,1557340142.260 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:29:03.836Z,1557340143.836 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:29:05.452Z,1557340145.452 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:29:07.108Z,1557340147.108 [Reporter](INFO): acoustic_contact_range 179.940002 m
2019-05-08T18:29:07.109Z,1557340147.109 [Reporter](INFO): DUSBL_Hydroid.xAngle -5.450000 arcdeg
2019-05-08T18:29:10.744Z,1557340150.744 [Reporter](INFO): acoustic_contact_range 179.279999 m
2019-05-08T18:29:10.744Z,1557340150.744 [Reporter](INFO): DUSBL_Hydroid.xAngle -4.700000 arcdeg
2019-05-08T18:29:12.771Z,1557340152.771 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:29:12.771Z,1557340152.771 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:29:12.771Z,1557340152.771 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater] Running Loop=10
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:29:12.772Z,1557340152.772 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:29:12.773Z,1557340152.773 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:29:14.385Z,1557340154.385 [Reporter](INFO): acoustic_contact_range 194.639999 m
2019-05-08T18:29:14.385Z,1557340154.385 [Reporter](INFO): DUSBL_Hydroid.xAngle -5.900000 arcdeg
2019-05-08T18:29:17.981Z,1557340157.981 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:29:22.020Z,1557340162.020 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:29:23.277Z,1557340163.277 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:29:23.277Z,1557340163.277 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:29:23.277Z,1557340163.277 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:29:23.278Z,1557340163.278 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:29:23.278Z,1557340163.278 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:29:23.278Z,1557340163.278 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:29:23.279Z,1557340163.279 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:29:23.279Z,1557340163.279 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:29:23.279Z,1557340163.279 [DUSBL](INFO): Completed DUSBL
2019-05-08T18:29:23.279Z,1557340163.279 [MissionManager](INFO): DUSBL is completed.
2019-05-08T18:29:23.280Z,1557340163.280 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-08T18:29:23.280Z,1557340163.280 [DUSBL] Stopped
2019-05-08T18:29:23.280Z,1557340163.280 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-08T18:29:23.280Z,1557340163.280 [DUSBL:A.Pitch] Stopped
2019-05-08T18:29:23.280Z,1557340163.280 [DUSBL:B.SetSpeed] Stopped
2019-05-08T18:29:23.280Z,1557340163.280 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-08T18:29:23.280Z,1557340163.280 [DUSBL:C] Stopped
2019-05-08T18:29:23.669Z,1557340163.669 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:29:23.669Z,1557340163.669 [Default] Running Loop=1
2019-05-08T18:29:23.669Z,1557340163.669 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:29:23.669Z,1557340163.669 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:29:23.670Z,1557340163.670 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:29:23.670Z,1557340163.670 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:29:23.670Z,1557340163.670 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:29:23.671Z,1557340163.671 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:29:23.671Z,1557340163.671 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:29:23.671Z,1557340163.671 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:29:23.672Z,1557340163.672 [Default:A.Wait] Running Loop=1
2019-05-08T18:29:23.672Z,1557340163.672 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:29:28.355Z,1557340168.355 [CommandLine](IMPORTANT): got command show variable detection
2019-05-08T18:29:28.444Z,1557340168.444 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-05-08T18:29:37.002Z,1557340177.002 [Default:A.Wait](INFO): Done Waiting.
2019-05-08T18:29:37.002Z,1557340177.002 [Default:A.Wait] Stopped
2019-05-08T18:29:37.002Z,1557340177.002 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:29:37.412Z,1557340177.412 [Default:CheckIn] Running Loop=1
2019-05-08T18:29:37.412Z,1557340177.412 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:29:37.412Z,1557340177.412 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:29:38.998Z,1557340178.998 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:29:39.421Z,1557340179.421 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182804.00,A,3648.14849,N,12147.19605,W,0.019,66.06,080519,,,D*46
2019-05-08T18:29:39.423Z,1557340179.423 [NAL9602](INFO): GPS fix at 20190508T182804: (36.802475, -121.786601)
2019-05-08T18:29:39.457Z,1557340179.457 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:29:39.457Z,1557340179.457 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:29:41.113Z,1557340181.113 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-05-08T18:29:41.629Z,1557340181.629 [CommandLine](IMPORTANT): got command get DUSBL_Hydroid.detectionThreshold
2019-05-08T18:29:41.630Z,1557340181.630 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold 20 count
2019-05-08T18:29:45.910Z,1557340185.910 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190508T181315/Courier0010.lzma
2019-05-08T18:29:46.716Z,1557340186.716 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0010.lzma.bak
2019-05-08T18:29:46.716Z,1557340186.716 [DataOverHttps](INFO): SBD MOMSN=10975499
2019-05-08T18:29:59.157Z,1557340199.157 [DataOverHttps](INFO): Sending 1933 bytes from file Logs/20190508T181315/Express0011.lzma
2019-05-08T18:29:59.960Z,1557340199.960 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0011.lzma.bak
2019-05-08T18:29:59.960Z,1557340199.960 [DataOverHttps](INFO): SBD MOMSN=10975502
2019-05-08T18:30:00.937Z,1557340200.937 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:30:00.938Z,1557340200.938 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:30:00.938Z,1557340200.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:30:01.710Z,1557340201.710 [NAL9602](INFO): SBD MO Status=0, MOMSN=3881, MT Status=0, MTMSN=0
2019-05-08T18:30:01.710Z,1557340201.710 [NAL9602](INFO): No messages in MT queue
2019-05-08T18:30:32.416Z,1557340232.416 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-08T18:35:01.533Z,1557340501.533 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-08T18:35:01.533Z,1557340501.533 [Default:CheckIn:C.Wait] Stopped
2019-05-08T18:35:01.533Z,1557340501.533 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:35:01.533Z,1557340501.533 [Default:CheckIn:D] Running Loop=1
2019-05-08T18:35:01.929Z,1557340501.929 [Default:CheckIn:D] Stopped
2019-05-08T18:35:01.929Z,1557340501.929 [Default:CheckIn:E] Running Loop=1
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.637665 min
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn:E] Stopped
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn] Stopped
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn](INFO): Running loop #2
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn] Running Loop=2
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:35:02.357Z,1557340502.357 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:35:03.938Z,1557340503.938 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:35:04.353Z,1557340504.353 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183329.00,A,3648.15019,N,12147.19822,W,0.058,66.06,080519,,,D*41
2019-05-08T18:35:04.355Z,1557340504.355 [NAL9602](INFO): GPS fix at 20190508T183329: (36.802503, -121.786637)
2019-05-08T18:35:04.416Z,1557340504.416 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:35:04.416Z,1557340504.416 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:35:06.048Z,1557340506.048 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-05-08T18:35:10.454Z,1557340510.454 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190508T181315/Courier0013.lzma
2019-05-08T18:35:11.260Z,1557340511.260 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0013.lzma.bak
2019-05-08T18:35:11.260Z,1557340511.260 [DataOverHttps](INFO): SBD MOMSN=10975644
2019-05-08T18:35:13.371Z,1557340513.371 [RDI_Pathfinder](ERROR): Failed to parse:
:B-3:BE,-32768,-32768,-32768,V
2019-05-08T18:35:25.327Z,1557340525.327 [DataOverHttps](INFO): Sending 785 bytes from file Logs/20190508T181315/Express0014.lzma
2019-05-08T18:35:26.166Z,1557340526.166 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0014.lzma.bak
2019-05-08T18:35:26.167Z,1557340526.167 [DataOverHttps](INFO): SBD MOMSN=10975647
2019-05-08T18:35:27.097Z,1557340527.097 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:35:27.097Z,1557340527.097 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:35:27.097Z,1557340527.097 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:35:35.134Z,1557340535.134 [NAL9602](INFO): SBD MO Status=0, MOMSN=3882, MT Status=0, MTMSN=0
2019-05-08T18:35:35.134Z,1557340535.134 [NAL9602](INFO): No messages in MT queue
2019-05-08T18:36:05.840Z,1557340565.840 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-08T18:39:53.107Z,1557340793.107 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:39:53.108Z,1557340793.108 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:39:53.164Z,1557340793.164 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-08T18:39:53.166Z,1557340793.166 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-08T18:39:53.169Z,1557340793.169 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-08T18:39:53.171Z,1557340793.171 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-08T18:39:53.173Z,1557340793.173 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-08T18:39:53.174Z,1557340793.174 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-08T18:39:53.179Z,1557340793.179 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-08T18:39:53.187Z,1557340793.187 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:39:53.191Z,1557340793.191 [MissionManager](DEBUG):
This mission is requests a DUSBL arming.
How long to let the mission run.
90
Number of pings to requst.
10
Transponder Address.
2
Number of pings requested each time.
1
Automatically set to true if the DUSBL is enabled. Set to false to disable
reading from the DUSBL.
0
10
2019-05-08T18:39:53.192Z,1557340793.192 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:39:53.313Z,1557340793.313 [Default] Stopped
2019-05-08T18:39:53.313Z,1557340793.313 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:39:53.313Z,1557340793.313 [Default:B.GoToSurface] Stopped
2019-05-08T18:39:53.313Z,1557340793.313 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:39:53.314Z,1557340793.314 [Default:CheckIn] Stopped
2019-05-08T18:39:53.314Z,1557340793.314 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:39:53.314Z,1557340793.314 [Default:CheckIn:C.Wait] Stopped
2019-05-08T18:39:53.314Z,1557340793.314 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:39:53.314Z,1557340793.314 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-08T18:39:53.314Z,1557340793.314 [DUSBL] Running Loop=1
2019-05-08T18:39:53.315Z,1557340793.315 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-08T18:39:53.315Z,1557340793.315 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:39:53.315Z,1557340793.315 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-08T18:39:53.315Z,1557340793.315 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:39:53.315Z,1557340793.315 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-08T18:39:53.315Z,1557340793.315 [DUSBL:C] Running Loop=1
2019-05-08T18:39:53.315Z,1557340793.315 [DUSBL:RequestRepeater] Running Loop=1
2019-05-08T18:39:53.316Z,1557340793.316 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:39:53.316Z,1557340793.316 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:39:53.316Z,1557340793.316 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:39:53.316Z,1557340793.316 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:39:53.316Z,1557340793.316 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:39:53.316Z,1557340793.316 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:39:53.316Z,1557340793.316 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:39:53.317Z,1557340793.317 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-08T18:39:53.318Z,1557340793.318 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-08T18:39:53.318Z,1557340793.318 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:39:53.318Z,1557340793.318 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:39:56.171Z,1557340796.171 [Reporter](INFO): acoustic_contact_range 142.679993 m
2019-05-08T18:39:56.172Z,1557340796.172 [Reporter](INFO): DUSBL_Hydroid.xAngle 22.850000 arcdeg
2019-05-08T18:39:59.752Z,1557340799.752 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:40:03.420Z,1557340803.420 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:40:03.420Z,1557340803.420 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:40:03.420Z,1557340803.420 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:40:03.420Z,1557340803.420 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater] Running Loop=2
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:40:03.421Z,1557340803.421 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:40:03.792Z,1557340803.792 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:40:05.469Z,1557340805.469 [Reporter](INFO): acoustic_contact_range 136.620010 m
2019-05-08T18:40:05.469Z,1557340805.469 [Reporter](INFO): DUSBL_Hydroid.xAngle 25.200000 arcdeg
2019-05-08T18:40:09.044Z,1557340809.044 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:40:13.919Z,1557340813.919 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:40:13.919Z,1557340813.919 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:40:13.919Z,1557340813.919 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater] Running Loop=3
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:40:13.920Z,1557340813.920 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:40:13.921Z,1557340813.921 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:40:13.921Z,1557340813.921 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:40:16.760Z,1557340816.760 [Reporter](INFO): acoustic_contact_range 136.740005 m
2019-05-08T18:40:16.760Z,1557340816.760 [Reporter](INFO): DUSBL_Hydroid.xAngle 29.000000 arcdeg
2019-05-08T18:40:20.399Z,1557340820.399 [Reporter](INFO): acoustic_contact_range 136.680008 m
2019-05-08T18:40:20.400Z,1557340820.399 [Reporter](INFO): DUSBL_Hydroid.xAngle 27.350000 arcdeg
2019-05-08T18:40:24.031Z,1557340824.031 [Reporter](INFO): acoustic_contact_range 132.839996 m
2019-05-08T18:40:24.032Z,1557340824.032 [Reporter](INFO): DUSBL_Hydroid.xAngle 24.100000 arcdeg
2019-05-08T18:40:24.437Z,1557340824.437 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:40:24.437Z,1557340824.437 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:40:24.437Z,1557340824.437 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:40:24.437Z,1557340824.437 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:40:24.438Z,1557340824.438 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:40:24.438Z,1557340824.438 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:40:24.438Z,1557340824.438 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:40:24.438Z,1557340824.438 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:40:24.438Z,1557340824.438 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-08T18:40:24.438Z,1557340824.438 [DUSBL:RequestRepeater] Running Loop=4
2019-05-08T18:40:24.438Z,1557340824.438 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:40:24.439Z,1557340824.439 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:40:24.439Z,1557340824.439 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:40:24.439Z,1557340824.439 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:40:24.439Z,1557340824.439 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:40:33.750Z,1557340833.750 [Reporter](INFO): acoustic_contact_range 132.839996 m
2019-05-08T18:40:33.751Z,1557340833.751 [Reporter](INFO): DUSBL_Hydroid.xAngle 21.049999 arcdeg
2019-05-08T18:40:34.954Z,1557340834.954 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:40:34.954Z,1557340834.954 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:40:34.954Z,1557340834.954 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:40:34.955Z,1557340834.955 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:40:34.955Z,1557340834.955 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater] Running Loop=5
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:40:34.956Z,1557340834.956 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:40:35.728Z,1557340835.728 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-08T18:40:35.728Z,1557340835.728 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 23.06, 23.06, 23.06
2019-05-08T18:40:37.436Z,1557340837.436 [Reporter](INFO): acoustic_contact_range 132.900009 m
2019-05-08T18:40:37.437Z,1557340837.437 [Reporter](INFO): DUSBL_Hydroid.xAngle 22.349999 arcdeg
2019-05-08T18:40:40.993Z,1557340840.993 [Reporter](INFO): acoustic_contact_range 132.779999 m
2019-05-08T18:40:40.993Z,1557340840.993 [Reporter](INFO): DUSBL_Hydroid.xAngle 23.250000 arcdeg
2019-05-08T18:40:44.600Z,1557340844.600 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:40:45.446Z,1557340845.446 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:40:45.447Z,1557340845.447 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:40:45.447Z,1557340845.447 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:40:45.448Z,1557340845.448 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:40:45.448Z,1557340845.448 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:40:45.448Z,1557340845.448 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:40:45.448Z,1557340845.448 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:40:45.448Z,1557340845.448 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:40:45.448Z,1557340845.448 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-08T18:40:45.448Z,1557340845.448 [DUSBL:RequestRepeater] Running Loop=6
2019-05-08T18:40:45.449Z,1557340845.449 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:40:45.449Z,1557340845.449 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:40:45.449Z,1557340845.449 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:40:45.449Z,1557340845.449 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:40:45.449Z,1557340845.449 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:40:48.635Z,1557340848.635 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:40:52.684Z,1557340852.684 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:40:54.428Z,1557340854.428 [Reporter](INFO): acoustic_contact_range 129.660004 m
2019-05-08T18:40:54.429Z,1557340854.429 [Reporter](INFO): DUSBL_Hydroid.xAngle 25.900000 arcdeg
2019-05-08T18:40:55.943Z,1557340855.943 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:40:55.943Z,1557340855.943 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:40:55.943Z,1557340855.943 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:40:55.944Z,1557340855.944 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:40:55.944Z,1557340855.944 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:40:55.944Z,1557340855.944 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:40:55.944Z,1557340855.944 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:40:55.944Z,1557340855.944 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:40:55.944Z,1557340855.944 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-08T18:40:55.945Z,1557340855.945 [DUSBL:RequestRepeater] Running Loop=7
2019-05-08T18:40:55.945Z,1557340855.945 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:40:55.945Z,1557340855.945 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:40:55.945Z,1557340855.945 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:40:55.945Z,1557340855.945 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:40:55.945Z,1557340855.945 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:40:57.967Z,1557340857.967 [Reporter](INFO): acoustic_contact_range 133.740005 m
2019-05-08T18:40:57.967Z,1557340857.967 [Reporter](INFO): DUSBL_Hydroid.xAngle 27.449999 arcdeg
2019-05-08T18:41:01.618Z,1557340861.618 [Reporter](INFO): acoustic_contact_range 173.399994 m
2019-05-08T18:41:01.619Z,1557340861.619 [Reporter](INFO): DUSBL_Hydroid.xAngle 27.000001 arcdeg
2019-05-08T18:41:05.267Z,1557340865.267 [Reporter](INFO): acoustic_contact_range 136.559998 m
2019-05-08T18:41:05.267Z,1557340865.267 [Reporter](INFO): DUSBL_Hydroid.xAngle 27.750000 arcdeg
2019-05-08T18:41:06.478Z,1557340866.478 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:41:06.478Z,1557340866.478 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:41:06.478Z,1557340866.478 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:41:06.479Z,1557340866.479 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:41:06.479Z,1557340866.479 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater] Running Loop=8
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:41:06.480Z,1557340866.480 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:41:08.839Z,1557340868.839 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:41:16.560Z,1557340876.560 [Reporter](INFO): acoustic_contact_range 134.100006 m
2019-05-08T18:41:16.561Z,1557340876.561 [Reporter](INFO): DUSBL_Hydroid.xAngle 24.350000 arcdeg
2019-05-08T18:41:16.945Z,1557340876.945 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:41:16.945Z,1557340876.945 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:41:16.945Z,1557340876.945 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:41:16.949Z,1557340876.949 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:41:16.949Z,1557340876.949 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:41:16.949Z,1557340876.949 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:41:16.949Z,1557340876.949 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:41:16.949Z,1557340876.949 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:41:16.949Z,1557340876.949 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-08T18:41:16.950Z,1557340876.950 [DUSBL:RequestRepeater] Running Loop=9
2019-05-08T18:41:16.950Z,1557340876.950 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:41:16.950Z,1557340876.950 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:41:16.950Z,1557340876.950 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:41:16.950Z,1557340876.950 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:41:16.950Z,1557340876.950 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:41:27.477Z,1557340887.477 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:41:27.477Z,1557340887.477 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:41:27.477Z,1557340887.477 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:41:27.478Z,1557340887.478 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:41:27.478Z,1557340887.478 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:41:27.482Z,1557340887.482 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater] Running Loop=10
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:41:27.483Z,1557340887.483 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:41:32.330Z,1557340892.330 [Reporter](INFO): acoustic_contact_range 134.100006 m
2019-05-08T18:41:32.333Z,1557340892.333 [Reporter](INFO): DUSBL_Hydroid.xAngle 22.500001 arcdeg
2019-05-08T18:41:37.951Z,1557340897.951 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:41:37.952Z,1557340897.952 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:41:37.952Z,1557340897.952 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:41:37.952Z,1557340897.952 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:41:37.952Z,1557340897.952 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:41:37.952Z,1557340897.952 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:41:37.952Z,1557340897.952 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:41:37.952Z,1557340897.952 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:41:37.953Z,1557340897.953 [DUSBL](INFO): Completed DUSBL
2019-05-08T18:41:37.953Z,1557340897.953 [MissionManager](INFO): DUSBL is completed.
2019-05-08T18:41:37.953Z,1557340897.953 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-08T18:41:37.953Z,1557340897.953 [DUSBL] Stopped
2019-05-08T18:41:37.954Z,1557340897.954 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-08T18:41:37.954Z,1557340897.954 [DUSBL:A.Pitch] Stopped
2019-05-08T18:41:37.954Z,1557340897.954 [DUSBL:B.SetSpeed] Stopped
2019-05-08T18:41:37.954Z,1557340897.954 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-08T18:41:37.954Z,1557340897.954 [DUSBL:C] Stopped
2019-05-08T18:41:38.357Z,1557340898.357 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:41:38.357Z,1557340898.357 [Default] Running Loop=1
2019-05-08T18:41:38.357Z,1557340898.357 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:41:38.358Z,1557340898.358 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:41:38.358Z,1557340898.358 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:41:38.358Z,1557340898.358 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:41:38.358Z,1557340898.358 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:41:38.359Z,1557340898.359 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:41:38.359Z,1557340898.359 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:41:38.359Z,1557340898.359 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:41:38.360Z,1557340898.360 [Default:A.Wait] Running Loop=1
2019-05-08T18:41:38.360Z,1557340898.360 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:41:41.585Z,1557340901.585 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:41:41.586Z,1557340901.586 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:41:41.681Z,1557340901.681 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-08T18:41:41.688Z,1557340901.688 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-08T18:41:41.690Z,1557340901.690 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-08T18:41:41.696Z,1557340901.696 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-08T18:41:41.702Z,1557340901.702 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-08T18:41:41.703Z,1557340901.703 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-08T18:41:41.712Z,1557340901.712 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-08T18:41:41.736Z,1557340901.736 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:41:41.744Z,1557340901.744 [MissionManager](DEBUG):
This mission is requests a DUSBL arming.
How long to let the mission run.
90
Number of pings to requst.
10
Transponder Address.
2
Number of pings requested each time.
1
Automatically set to true if the DUSBL is enabled. Set to false to disable
reading from the DUSBL.
0
10
2019-05-08T18:41:41.746Z,1557340901.746 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:41:41.989Z,1557340901.989 [Default] Stopped
2019-05-08T18:41:41.990Z,1557340901.990 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:41:41.991Z,1557340901.991 [Default:A.Wait] Stopped
2019-05-08T18:41:41.991Z,1557340901.991 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:41:41.992Z,1557340901.992 [Default:B.GoToSurface] Stopped
2019-05-08T18:41:41.992Z,1557340901.992 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:41:41.992Z,1557340901.992 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-08T18:41:41.992Z,1557340901.992 [DUSBL] Running Loop=1
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL:C] Running Loop=1
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL:RequestRepeater] Running Loop=1
2019-05-08T18:41:41.993Z,1557340901.993 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:41:41.994Z,1557340901.994 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:41:41.994Z,1557340901.994 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:41:41.994Z,1557340901.994 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:41:41.994Z,1557340901.994 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:41:41.994Z,1557340901.994 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:41:41.995Z,1557340901.995 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:41:41.995Z,1557340901.995 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-08T18:41:41.996Z,1557340901.996 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-08T18:41:41.996Z,1557340901.996 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:41:41.996Z,1557340901.996 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:41:44.798Z,1557340904.798 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:41:46.480Z,1557340906.480 [Reporter](INFO): acoustic_contact_range 172.440018 m
2019-05-08T18:41:46.480Z,1557340906.480 [Reporter](INFO): DUSBL_Hydroid.xAngle 26.199999 arcdeg
2019-05-08T18:41:52.094Z,1557340912.094 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:41:52.094Z,1557340912.094 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:41:52.095Z,1557340912.095 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:41:52.095Z,1557340912.095 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:41:52.095Z,1557340912.095 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater] Running Loop=2
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:41:52.096Z,1557340912.096 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:41:52.468Z,1557340912.468 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:42:00.183Z,1557340920.183 [Reporter](INFO): acoustic_contact_range 133.199997 m
2019-05-08T18:42:00.184Z,1557340920.184 [Reporter](INFO): DUSBL_Hydroid.xAngle 24.150000 arcdeg
2019-05-08T18:42:02.643Z,1557340922.643 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:42:02.643Z,1557340922.643 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:42:02.643Z,1557340922.643 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:42:02.643Z,1557340922.643 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:42:02.643Z,1557340922.643 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater] Running Loop=3
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:42:02.644Z,1557340922.644 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:42:13.099Z,1557340933.099 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:42:13.099Z,1557340933.099 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:42:13.099Z,1557340933.099 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater] Running Loop=4
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:42:13.100Z,1557340933.100 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:42:13.101Z,1557340933.101 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:42:22.015Z,1557340942.015 [Reporter](INFO): acoustic_contact_range 136.500000 m
2019-05-08T18:42:22.016Z,1557340942.016 [Reporter](INFO): DUSBL_Hydroid.xAngle 26.450000 arcdeg
2019-05-08T18:42:23.602Z,1557340943.602 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:42:23.602Z,1557340943.602 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:42:23.602Z,1557340943.602 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:42:23.603Z,1557340943.603 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:42:23.603Z,1557340943.603 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:42:23.603Z,1557340943.603 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:42:23.603Z,1557340943.603 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:42:23.603Z,1557340943.603 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:42:23.604Z,1557340943.604 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-08T18:42:23.604Z,1557340943.604 [DUSBL:RequestRepeater] Running Loop=5
2019-05-08T18:42:23.604Z,1557340943.604 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:42:23.604Z,1557340943.604 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:42:23.604Z,1557340943.604 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:42:23.604Z,1557340943.604 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:42:23.604Z,1557340943.604 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:42:25.641Z,1557340945.641 [Reporter](INFO): acoustic_contact_range 167.279999 m
2019-05-08T18:42:25.641Z,1557340945.641 [Reporter](INFO): DUSBL_Hydroid.xAngle 24.249999 arcdeg
2019-05-08T18:42:29.236Z,1557340949.236 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:42:33.276Z,1557340953.276 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:42:34.153Z,1557340954.153 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:42:34.153Z,1557340954.153 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:42:34.153Z,1557340954.153 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:42:34.154Z,1557340954.154 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:42:34.156Z,1557340954.156 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:42:34.156Z,1557340954.156 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:42:34.156Z,1557340954.156 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:42:34.156Z,1557340954.156 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:42:34.156Z,1557340954.156 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-08T18:42:34.156Z,1557340954.156 [DUSBL:RequestRepeater] Running Loop=6
2019-05-08T18:42:34.157Z,1557340954.157 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:42:34.157Z,1557340954.157 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:42:34.157Z,1557340954.157 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:42:34.157Z,1557340954.157 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:42:34.157Z,1557340954.157 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:42:34.892Z,1557340954.892 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:42:38.928Z,1557340958.928 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:42:44.630Z,1557340964.630 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:42:44.630Z,1557340964.630 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:42:44.631Z,1557340964.631 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:42:44.631Z,1557340964.631 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:42:44.631Z,1557340964.631 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater] Running Loop=7
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:42:44.632Z,1557340964.632 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:42:52.685Z,1557340972.685 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-08T18:42:52.685Z,1557340972.685 [RDI_Pathfinder](ERROR): Failed to parse:
:TS1502948,35.0, -0.1, 0.0,1448.9, 0
2019-05-08T18:42:55.128Z,1557340975.128 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:42:55.128Z,1557340975.128 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:42:55.128Z,1557340975.128 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:42:55.128Z,1557340975.128 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater] Running Loop=8
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:42:55.129Z,1557340975.129 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:43:05.633Z,1557340985.633 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:43:05.633Z,1557340985.633 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:43:05.633Z,1557340985.633 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:43:05.634Z,1557340985.634 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater] Running Loop=9
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:43:05.635Z,1557340985.635 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:43:13.268Z,1557340993.268 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:43:16.123Z,1557340996.123 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:43:16.123Z,1557340996.123 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:43:16.123Z,1557340996.123 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:43:16.124Z,1557340996.124 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:43:16.124Z,1557340996.124 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:43:16.124Z,1557340996.124 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:43:16.124Z,1557340996.124 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:43:16.124Z,1557340996.124 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:43:16.124Z,1557340996.124 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-08T18:43:16.125Z,1557340996.125 [DUSBL:RequestRepeater] Running Loop=10
2019-05-08T18:43:16.125Z,1557340996.125 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:43:16.125Z,1557340996.125 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:43:16.125Z,1557340996.125 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:43:16.125Z,1557340996.125 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:43:16.125Z,1557340996.125 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:43:26.679Z,1557341006.679 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:43:26.680Z,1557341006.680 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:43:26.680Z,1557341006.680 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:43:26.680Z,1557341006.680 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:43:26.680Z,1557341006.680 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:43:26.680Z,1557341006.680 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:43:26.680Z,1557341006.680 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:43:26.681Z,1557341006.681 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:43:26.681Z,1557341006.681 [DUSBL](INFO): Completed DUSBL
2019-05-08T18:43:26.681Z,1557341006.681 [MissionManager](INFO): DUSBL is completed.
2019-05-08T18:43:26.681Z,1557341006.681 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-08T18:43:26.682Z,1557341006.682 [DUSBL] Stopped
2019-05-08T18:43:26.682Z,1557341006.682 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-08T18:43:26.682Z,1557341006.682 [DUSBL:A.Pitch] Stopped
2019-05-08T18:43:26.682Z,1557341006.682 [DUSBL:B.SetSpeed] Stopped
2019-05-08T18:43:26.682Z,1557341006.682 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-08T18:43:26.682Z,1557341006.682 [DUSBL:C] Stopped
2019-05-08T18:43:27.033Z,1557341007.033 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:43:27.033Z,1557341007.033 [Default] Running Loop=1
2019-05-08T18:43:27.033Z,1557341007.033 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:43:27.033Z,1557341007.033 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:43:27.033Z,1557341007.033 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:43:27.034Z,1557341007.034 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:43:27.034Z,1557341007.034 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:43:27.034Z,1557341007.034 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:43:27.035Z,1557341007.035 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:43:27.035Z,1557341007.035 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:43:27.035Z,1557341007.035 [Default:A.Wait] Running Loop=1
2019-05-08T18:43:27.036Z,1557341007.036 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:43:40.386Z,1557341020.386 [Default:A.Wait](INFO): Done Waiting.
2019-05-08T18:43:40.386Z,1557341020.386 [Default:A.Wait] Stopped
2019-05-08T18:43:40.386Z,1557341020.386 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:43:40.770Z,1557341020.770 [Default:CheckIn] Running Loop=1
2019-05-08T18:43:40.770Z,1557341020.770 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:43:40.770Z,1557341020.770 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:43:42.370Z,1557341022.370 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:42.766Z,1557341022.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184207.00,A,3648.15026,N,12147.20008,W,0.097,66.06,080519,,,D*4E
2019-05-08T18:43:42.768Z,1557341022.768 [NAL9602](INFO): GPS fix at 20190508T184207: (36.802504, -121.786668)
2019-05-08T18:43:42.791Z,1557341022.791 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:43:42.792Z,1557341022.792 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:43:44.914Z,1557341024.914 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-05-08T18:43:49.046Z,1557341029.046 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T181315/Courier0016.lzma
2019-05-08T18:43:49.852Z,1557341029.852 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0016.lzma.bak
2019-05-08T18:43:49.852Z,1557341029.852 [DataOverHttps](INFO): SBD MOMSN=10975762
2019-05-08T18:44:01.058Z,1557341041.058 [NAL9602](INFO): SBD MO Status=0, MOMSN=3883, MT Status=0, MTMSN=0
2019-05-08T18:44:01.058Z,1557341041.058 [NAL9602](INFO): No messages in MT queue
2019-05-08T18:44:02.241Z,1557341042.241 [DataOverHttps](INFO): Sending 1290 bytes from file Logs/20190508T181315/Express0017.lzma
2019-05-08T18:44:03.044Z,1557341043.044 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0017.lzma.bak
2019-05-08T18:44:03.044Z,1557341043.044 [DataOverHttps](INFO): SBD MOMSN=10975765
2019-05-08T18:44:04.372Z,1557341044.372 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:44:04.372Z,1557341044.372 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:44:04.373Z,1557341044.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:44:06.354Z,1557341046.354 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-08T18:44:06.354Z,1557341046.354 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-32BE,-32768,-32768,-32768,V
2019-05-08T18:44:31.768Z,1557341071.768 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-08T18:49:04.893Z,1557341344.893 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-08T18:49:04.893Z,1557341344.893 [Default:CheckIn:C.Wait] Stopped
2019-05-08T18:49:04.893Z,1557341344.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:49:04.893Z,1557341344.893 [Default:CheckIn:D] Running Loop=1
2019-05-08T18:49:05.294Z,1557341345.294 [Default:CheckIn:D] Stopped
2019-05-08T18:49:05.295Z,1557341345.295 [Default:CheckIn:E] Running Loop=1
2019-05-08T18:49:05.709Z,1557341345.709 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.637683 min
2019-05-08T18:49:05.709Z,1557341345.709 [Default:CheckIn:E] Stopped
2019-05-08T18:49:05.709Z,1557341345.709 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-08T18:49:05.709Z,1557341345.709 [Default:CheckIn] Stopped
2019-05-08T18:49:05.709Z,1557341345.709 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:49:05.709Z,1557341345.709 [Default:CheckIn](INFO): Running loop #2
2019-05-08T18:49:05.709Z,1557341345.709 [Default:CheckIn] Running Loop=2
2019-05-08T18:49:05.710Z,1557341345.710 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:49:05.710Z,1557341345.710 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:49:07.302Z,1557341347.302 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:07.701Z,1557341347.701 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184732.00,A,3648.15156,N,12147.19940,W,0.058,0.00,080519,,,D*71
2019-05-08T18:49:07.704Z,1557341347.704 [NAL9602](INFO): GPS fix at 20190508T184732: (36.802526, -121.786657)
2019-05-08T18:49:07.773Z,1557341347.773 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:49:07.773Z,1557341347.773 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:49:13.746Z,1557341353.746 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190508T181315/Courier0019.lzma
2019-05-08T18:49:14.552Z,1557341354.552 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0019.lzma.bak
2019-05-08T18:49:14.553Z,1557341354.553 [DataOverHttps](INFO): SBD MOMSN=10975826
2019-05-08T18:49:23.618Z,1557341363.618 [NAL9602](INFO): SBD MO Status=0, MOMSN=3884, MT Status=0, MTMSN=0
2019-05-08T18:49:23.618Z,1557341363.618 [NAL9602](INFO): No messages in MT queue
2019-05-08T18:49:29.476Z,1557341369.476 [DataOverHttps](INFO): Sending 770 bytes from file Logs/20190508T181315/Express0020.lzma
2019-05-08T18:49:30.280Z,1557341370.280 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0020.lzma.bak
2019-05-08T18:49:30.280Z,1557341370.280 [DataOverHttps](INFO): SBD MOMSN=10975829
2019-05-08T18:49:31.353Z,1557341371.353 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:49:31.353Z,1557341371.353 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:49:31.353Z,1557341371.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:49:54.347Z,1557341394.347 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-08T18:50:32.353Z,1557341432.353 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-08T18:50:32.353Z,1557341432.353 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-3268,-32768,V
2019-05-08T18:50:57.515Z,1557341457.515 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:50:57.516Z,1557341457.516 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:50:57.544Z,1557341457.544 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-08T18:50:57.546Z,1557341457.546 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-08T18:50:57.567Z,1557341457.567 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-08T18:50:57.569Z,1557341457.569 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-08T18:50:57.581Z,1557341457.581 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-08T18:50:57.582Z,1557341457.582 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-08T18:50:57.604Z,1557341457.604 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-08T18:50:57.624Z,1557341457.624 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:50:57.641Z,1557341457.641 [MissionManager](DEBUG):
This mission is requests a DUSBL arming.
How long to let the mission run.
90
Number of pings to requst.
10
Transponder Address.
2
Number of pings requested each time.
1
Automatically set to true if the DUSBL is enabled. Set to false to disable
reading from the DUSBL.
0
10
2019-05-08T18:50:57.655Z,1557341457.655 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:50:57.789Z,1557341457.789 [Default] Stopped
2019-05-08T18:50:57.789Z,1557341457.789 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:50:57.789Z,1557341457.789 [Default:B.GoToSurface] Stopped
2019-05-08T18:50:57.789Z,1557341457.789 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:50:57.789Z,1557341457.789 [Default:CheckIn] Stopped
2019-05-08T18:50:57.789Z,1557341457.789 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:50:57.789Z,1557341457.789 [Default:CheckIn:C.Wait] Stopped
2019-05-08T18:50:57.790Z,1557341457.790 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:50:57.790Z,1557341457.790 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-08T18:50:57.790Z,1557341457.790 [DUSBL] Running Loop=1
2019-05-08T18:50:57.790Z,1557341457.790 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-08T18:50:57.790Z,1557341457.790 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:50:57.790Z,1557341457.790 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-08T18:50:57.791Z,1557341457.791 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:50:57.791Z,1557341457.791 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-08T18:50:57.791Z,1557341457.791 [DUSBL:C] Running Loop=1
2019-05-08T18:50:57.791Z,1557341457.791 [DUSBL:RequestRepeater] Running Loop=1
2019-05-08T18:50:57.791Z,1557341457.791 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:50:57.791Z,1557341457.791 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:50:57.791Z,1557341457.791 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:50:57.792Z,1557341457.792 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:50:57.792Z,1557341457.792 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:50:57.792Z,1557341457.792 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:50:57.792Z,1557341457.792 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:50:57.793Z,1557341457.793 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-08T18:50:57.793Z,1557341457.793 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-08T18:50:57.794Z,1557341457.794 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:50:57.794Z,1557341457.794 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:51:03.004Z,1557341463.004 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:51:04.701Z,1557341464.701 [Reporter](INFO): acoustic_contact_range 98.580002 m
2019-05-08T18:51:04.702Z,1557341464.702 [Reporter](INFO): DUSBL_Hydroid.xAngle 47.500001 arcdeg
2019-05-08T18:51:07.884Z,1557341467.884 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-08T18:51:07.885Z,1557341467.885 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19050811584448,35.0, -0.1,448.9, 0
2019-05-08T18:51:07.893Z,1557341467.893 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:51:07.893Z,1557341467.893 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:51:07.893Z,1557341467.893 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater] Running Loop=2
2019-05-08T18:51:07.894Z,1557341467.894 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:51:07.895Z,1557341467.895 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:51:07.895Z,1557341467.895 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:51:07.895Z,1557341467.895 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:51:07.895Z,1557341467.895 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:51:08.252Z,1557341468.252 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:51:15.967Z,1557341475.967 [Reporter](INFO): acoustic_contact_range 89.820007 m
2019-05-08T18:51:15.968Z,1557341475.968 [Reporter](INFO): DUSBL_Hydroid.xAngle -12.000000 arcdeg
2019-05-08T18:51:18.423Z,1557341478.423 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:51:18.423Z,1557341478.423 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:51:18.423Z,1557341478.423 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:51:18.424Z,1557341478.424 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:51:18.424Z,1557341478.424 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:51:18.424Z,1557341478.424 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:51:18.424Z,1557341478.424 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:51:18.424Z,1557341478.424 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:51:18.425Z,1557341478.425 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-08T18:51:18.425Z,1557341478.425 [DUSBL:RequestRepeater] Running Loop=3
2019-05-08T18:51:18.425Z,1557341478.425 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:51:18.425Z,1557341478.425 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:51:18.425Z,1557341478.425 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:51:18.425Z,1557341478.425 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:51:18.425Z,1557341478.425 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:51:19.659Z,1557341479.659 [Reporter](INFO): acoustic_contact_range 89.879997 m
2019-05-08T18:51:19.659Z,1557341479.659 [Reporter](INFO): DUSBL_Hydroid.xAngle -8.750000 arcdeg
2019-05-08T18:51:23.200Z,1557341483.200 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:51:28.901Z,1557341488.901 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:51:28.901Z,1557341488.901 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:51:28.901Z,1557341488.901 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:51:28.902Z,1557341488.902 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:51:28.902Z,1557341488.902 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater] Running Loop=4
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:51:28.903Z,1557341488.903 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:51:33.304Z,1557341493.304 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:51:34.920Z,1557341494.920 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:51:38.956Z,1557341498.956 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:51:39.400Z,1557341499.400 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:51:39.400Z,1557341499.400 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:51:39.400Z,1557341499.400 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater] Running Loop=5
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:51:39.401Z,1557341499.401 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:51:39.402Z,1557341499.402 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:51:39.402Z,1557341499.402 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:51:39.402Z,1557341499.402 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:51:40.576Z,1557341500.576 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:51:42.259Z,1557341502.259 [Reporter](INFO): acoustic_contact_range 92.580002 m
2019-05-08T18:51:42.260Z,1557341502.260 [Reporter](INFO): DUSBL_Hydroid.xAngle -12.150000 arcdeg
2019-05-08T18:51:45.828Z,1557341505.828 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:51:49.868Z,1557341509.868 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:51:49.893Z,1557341509.893 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:51:49.893Z,1557341509.893 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:51:49.893Z,1557341509.893 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:51:49.894Z,1557341509.894 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:51:49.894Z,1557341509.894 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:51:49.894Z,1557341509.894 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater] Running Loop=6
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:51:49.895Z,1557341509.895 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:51:51.484Z,1557341511.484 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:51:52.353Z,1557341512.353 [RDI_Pathfinder](ERROR): Failed to parse:768,-32768,-32768,V
2019-05-08T18:52:00.394Z,1557341520.394 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:52:00.394Z,1557341520.394 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:52:00.394Z,1557341520.394 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater] Running Loop=7
2019-05-08T18:52:00.395Z,1557341520.395 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:52:00.396Z,1557341520.396 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:52:00.396Z,1557341520.396 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:52:00.396Z,1557341520.396 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:52:00.396Z,1557341520.396 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:52:10.913Z,1557341530.913 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:52:10.913Z,1557341530.913 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:52:10.914Z,1557341530.914 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:52:10.914Z,1557341530.914 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:52:10.914Z,1557341530.914 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater] Running Loop=8
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:52:10.915Z,1557341530.915 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:52:17.397Z,1557341537.397 [Reporter](INFO): acoustic_contact_range 95.400009 m
2019-05-08T18:52:17.397Z,1557341537.397 [Reporter](INFO): DUSBL_Hydroid.xAngle -11.500000 arcdeg
2019-05-08T18:52:21.040Z,1557341541.040 [Reporter](INFO): acoustic_contact_range 100.920006 m
2019-05-08T18:52:21.040Z,1557341541.040 [Reporter](INFO): DUSBL_Hydroid.xAngle -11.450000 arcdeg
2019-05-08T18:52:21.422Z,1557341541.422 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:52:21.423Z,1557341541.423 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:52:21.423Z,1557341541.423 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:52:21.423Z,1557341541.423 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater] Running Loop=9
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:52:21.424Z,1557341541.424 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:52:24.612Z,1557341544.612 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:52:28.652Z,1557341548.652 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:52:31.912Z,1557341551.912 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:52:31.912Z,1557341551.912 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:52:31.912Z,1557341551.912 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:52:31.912Z,1557341551.912 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater] Running Loop=10
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:52:31.913Z,1557341551.913 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:52:36.444Z,1557341556.444 [Reporter](INFO): acoustic_contact_range 96.899994 m
2019-05-08T18:52:36.445Z,1557341556.445 [Reporter](INFO): DUSBL_Hydroid.xAngle -12.900000 arcdeg
2019-05-08T18:52:42.449Z,1557341562.449 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:52:42.449Z,1557341562.449 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:52:42.449Z,1557341562.449 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:52:42.450Z,1557341562.450 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:52:42.450Z,1557341562.450 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:52:42.450Z,1557341562.450 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:52:42.450Z,1557341562.450 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:52:42.450Z,1557341562.450 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:52:42.451Z,1557341562.451 [DUSBL](INFO): Completed DUSBL
2019-05-08T18:52:42.451Z,1557341562.451 [MissionManager](INFO): DUSBL is completed.
2019-05-08T18:52:42.451Z,1557341562.451 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-08T18:52:42.451Z,1557341562.451 [DUSBL] Stopped
2019-05-08T18:52:42.451Z,1557341562.451 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-08T18:52:42.451Z,1557341562.451 [DUSBL:A.Pitch] Stopped
2019-05-08T18:52:42.451Z,1557341562.451 [DUSBL:B.SetSpeed] Stopped
2019-05-08T18:52:42.451Z,1557341562.451 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-08T18:52:42.451Z,1557341562.451 [DUSBL:C] Stopped
2019-05-08T18:52:42.813Z,1557341562.813 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:52:42.814Z,1557341562.814 [Default] Running Loop=1
2019-05-08T18:52:42.814Z,1557341562.814 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:52:42.814Z,1557341562.814 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:52:42.814Z,1557341562.814 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:52:42.814Z,1557341562.814 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:52:42.815Z,1557341562.815 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:52:42.815Z,1557341562.815 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:52:42.815Z,1557341562.815 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:52:42.816Z,1557341562.816 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:52:42.816Z,1557341562.816 [Default:A.Wait] Running Loop=1
2019-05-08T18:52:42.816Z,1557341562.816 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:52:46.016Z,1557341566.016 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:52:46.017Z,1557341566.017 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:52:46.100Z,1557341566.100 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-08T18:52:46.102Z,1557341566.102 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-08T18:52:46.104Z,1557341566.104 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-08T18:52:46.111Z,1557341566.111 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-08T18:52:46.113Z,1557341566.113 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-08T18:52:46.114Z,1557341566.114 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-08T18:52:46.126Z,1557341566.126 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-08T18:52:46.138Z,1557341566.138 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:52:46.144Z,1557341566.144 [MissionManager](DEBUG):
This mission is requests a DUSBL arming.
How long to let the mission run.
90
Number of pings to requst.
10
Transponder Address.
2
Number of pings requested each time.
1
Automatically set to true if the DUSBL is enabled. Set to false to disable
reading from the DUSBL.
0
10
2019-05-08T18:52:46.145Z,1557341566.145 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-08T18:52:46.457Z,1557341566.457 [Default] Stopped
2019-05-08T18:52:46.458Z,1557341566.458 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:52:46.458Z,1557341566.458 [Default:A.Wait] Stopped
2019-05-08T18:52:46.458Z,1557341566.458 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:52:46.458Z,1557341566.458 [Default:B.GoToSurface] Stopped
2019-05-08T18:52:46.458Z,1557341566.458 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:52:46.458Z,1557341566.458 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-08T18:52:46.458Z,1557341566.458 [DUSBL] Running Loop=1
2019-05-08T18:52:46.459Z,1557341566.459 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-08T18:52:46.459Z,1557341566.459 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:52:46.459Z,1557341566.459 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-08T18:52:46.459Z,1557341566.459 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:52:46.459Z,1557341566.459 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-08T18:52:46.459Z,1557341566.459 [DUSBL:C] Running Loop=1
2019-05-08T18:52:46.459Z,1557341566.459 [DUSBL:RequestRepeater] Running Loop=1
2019-05-08T18:52:46.460Z,1557341566.460 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:52:46.460Z,1557341566.460 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:52:46.460Z,1557341566.460 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:52:46.460Z,1557341566.460 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:52:46.460Z,1557341566.460 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:52:46.460Z,1557341566.460 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:52:46.460Z,1557341566.460 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:52:46.461Z,1557341566.461 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-08T18:52:46.462Z,1557341566.462 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-08T18:52:46.462Z,1557341566.462 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-08T18:52:46.462Z,1557341566.462 [DUSBL:A.Pitch] Running Loop=1
2019-05-08T18:52:49.252Z,1557341569.252 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:52:56.576Z,1557341576.576 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:52:56.576Z,1557341576.576 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:52:56.576Z,1557341576.576 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:52:56.577Z,1557341576.577 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:52:56.577Z,1557341576.577 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:52:56.577Z,1557341576.577 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:52:56.577Z,1557341576.577 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:52:56.577Z,1557341576.577 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:52:56.578Z,1557341576.578 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-08T18:52:56.578Z,1557341576.578 [DUSBL:RequestRepeater] Running Loop=2
2019-05-08T18:52:56.578Z,1557341576.578 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:52:56.578Z,1557341576.578 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:52:56.578Z,1557341576.578 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:52:56.578Z,1557341576.578 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:52:56.578Z,1557341576.578 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:53:07.059Z,1557341587.059 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:53:07.059Z,1557341587.059 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:53:07.059Z,1557341587.059 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:53:07.060Z,1557341587.060 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:53:07.060Z,1557341587.060 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:53:07.060Z,1557341587.060 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:53:07.060Z,1557341587.060 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:53:07.060Z,1557341587.060 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:53:07.060Z,1557341587.060 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-08T18:53:07.060Z,1557341587.060 [DUSBL:RequestRepeater] Running Loop=3
2019-05-08T18:53:07.061Z,1557341587.061 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:53:07.061Z,1557341587.061 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:53:07.061Z,1557341587.061 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:53:07.061Z,1557341587.061 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:53:07.061Z,1557341587.061 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:53:09.052Z,1557341589.052 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:53:16.724Z,1557341596.724 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:53:17.593Z,1557341597.593 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:53:17.593Z,1557341597.593 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:53:17.593Z,1557341597.593 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:53:17.594Z,1557341597.594 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:53:17.594Z,1557341597.594 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:53:17.595Z,1557341597.595 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:53:17.595Z,1557341597.595 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:53:17.595Z,1557341597.595 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:53:17.595Z,1557341597.595 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-08T18:53:17.595Z,1557341597.595 [DUSBL:RequestRepeater] Running Loop=4
2019-05-08T18:53:17.595Z,1557341597.595 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:53:17.595Z,1557341597.595 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:53:17.596Z,1557341597.596 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:53:17.596Z,1557341597.596 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:53:17.596Z,1557341597.596 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:53:20.764Z,1557341600.764 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:53:28.089Z,1557341608.089 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:53:28.089Z,1557341608.089 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:53:28.089Z,1557341608.089 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:53:28.090Z,1557341608.090 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater] Running Loop=5
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:53:28.091Z,1557341608.091 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:53:38.591Z,1557341618.591 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:53:38.591Z,1557341618.591 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:53:38.591Z,1557341618.591 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater] Running Loop=6
2019-05-08T18:53:38.592Z,1557341618.592 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:53:38.593Z,1557341618.593 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:53:38.593Z,1557341618.593 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:53:38.593Z,1557341618.593 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:53:38.593Z,1557341618.593 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:53:40.564Z,1557341620.564 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:53:48.296Z,1557341628.296 [Reporter](INFO): acoustic_contact_range 90.420006 m
2019-05-08T18:53:48.296Z,1557341628.296 [Reporter](INFO): DUSBL_Hydroid.xAngle -12.050000 arcdeg
2019-05-08T18:53:49.073Z,1557341629.073 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:53:49.073Z,1557341629.073 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:53:49.073Z,1557341629.073 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:53:49.074Z,1557341629.074 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:53:49.074Z,1557341629.074 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:53:49.074Z,1557341629.074 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater] Running Loop=7
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:53:49.075Z,1557341629.075 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:53:51.872Z,1557341631.872 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:53:53.496Z,1557341633.496 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:53:59.585Z,1557341639.585 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:53:59.585Z,1557341639.585 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:53:59.585Z,1557341639.585 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:53:59.586Z,1557341639.586 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:53:59.586Z,1557341639.586 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:53:59.586Z,1557341639.586 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater] Running Loop=8
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:53:59.587Z,1557341639.587 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:54:01.221Z,1557341641.221 [Reporter](INFO): acoustic_contact_range 90.660004 m
2019-05-08T18:54:01.222Z,1557341641.222 [Reporter](INFO): DUSBL_Hydroid.xAngle -13.750000 arcdeg
2019-05-08T18:54:04.804Z,1557341644.804 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:54:06.416Z,1557341646.416 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:54:10.079Z,1557341650.079 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:54:10.079Z,1557341650.079 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:54:10.079Z,1557341650.079 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:54:10.080Z,1557341650.080 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:54:10.080Z,1557341650.080 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:54:10.080Z,1557341650.080 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:54:10.080Z,1557341650.080 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:54:10.080Z,1557341650.080 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:54:10.081Z,1557341650.081 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-08T18:54:10.081Z,1557341650.081 [DUSBL:RequestRepeater] Running Loop=9
2019-05-08T18:54:10.081Z,1557341650.081 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:54:10.081Z,1557341650.081 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:54:10.081Z,1557341650.081 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:54:10.081Z,1557341650.081 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:54:10.081Z,1557341650.081 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:54:10.460Z,1557341650.460 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:54:12.079Z,1557341652.079 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-05-08T18:54:13.302Z,1557341653.302 [Micromodem](ERROR): Response from modem failed NMEA checksum: $SNPGT,1450C0370,1000,24000,0,0,0,0,2000,0*4E
2019-05-08T18:54:13.303Z,1557341653.303 [Micromodem](ERROR): Response from modem unexpected: $CATXP,280*48
2019-05-08T18:54:13.692Z,1557341653.692 [Micromodem](ERROR): Response from modem unexpected: $CATXF,280*5E
2019-05-08T18:54:13.693Z,1557341653.693 [Micromodem](ERROR): Response from modem unexpected: $SNTTA,,,,,185412.73*51
2019-05-08T18:54:20.629Z,1557341660.629 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:54:20.629Z,1557341660.629 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:54:20.629Z,1557341660.629 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:54:20.630Z,1557341660.630 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:54:20.630Z,1557341660.630 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:54:20.630Z,1557341660.630 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:54:20.630Z,1557341660.630 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:54:20.630Z,1557341660.630 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:54:20.630Z,1557341660.630 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-08T18:54:20.638Z,1557341660.638 [DUSBL:RequestRepeater] Running Loop=10
2019-05-08T18:54:20.639Z,1557341660.639 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-08T18:54:20.639Z,1557341660.639 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-08T18:54:20.639Z,1557341660.639 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-08T18:54:20.639Z,1557341660.639 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-08T18:54:20.639Z,1557341660.639 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:54:24.192Z,1557341664.192 [Micromodem](ERROR): Nmea resend: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53
2019-05-08T18:54:28.236Z,1557341668.236 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-05-08T18:54:31.088Z,1557341671.088 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-08T18:54:31.088Z,1557341671.088 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-08T18:54:31.088Z,1557341671.088 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:54:31.089Z,1557341671.089 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-08T18:54:31.089Z,1557341671.089 [DUSBL:RequestRepeater] Stopped
2019-05-08T18:54:31.089Z,1557341671.089 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-08T18:54:31.089Z,1557341671.089 [DUSBL:RequestRepeater:A] Stopped
2019-05-08T18:54:31.089Z,1557341671.089 [DUSBL:RequestRepeater:B] Stopped
2019-05-08T18:54:31.089Z,1557341671.089 [DUSBL](INFO): Completed DUSBL
2019-05-08T18:54:31.090Z,1557341671.090 [MissionManager](INFO): DUSBL is completed.
2019-05-08T18:54:31.090Z,1557341671.090 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-08T18:54:31.090Z,1557341671.090 [DUSBL] Stopped
2019-05-08T18:54:31.091Z,1557341671.091 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-08T18:54:31.091Z,1557341671.091 [DUSBL:A.Pitch] Stopped
2019-05-08T18:54:31.091Z,1557341671.091 [DUSBL:B.SetSpeed] Stopped
2019-05-08T18:54:31.091Z,1557341671.091 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-08T18:54:31.091Z,1557341671.091 [DUSBL:C] Stopped
2019-05-08T18:54:31.498Z,1557341671.498 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:54:31.499Z,1557341671.499 [Default] Running Loop=1
2019-05-08T18:54:31.499Z,1557341671.499 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:54:31.499Z,1557341671.499 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:54:31.499Z,1557341671.499 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:54:31.499Z,1557341671.499 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:54:31.499Z,1557341671.499 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:54:31.500Z,1557341671.500 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:54:31.500Z,1557341671.500 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:54:31.500Z,1557341671.500 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:54:31.501Z,1557341671.501 [Default:A.Wait] Running Loop=1
2019-05-08T18:54:31.501Z,1557341671.501 [Default:A.Wait](DEBUG): Initialize Wait Component.