2019-08-09T21:42:02.753Z,1565386922.753 [Supervisor](DEBUG): Initializing supervisor.
2019-08-09T21:42:02.756Z,1565386922.756 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-09T21:42:02.757Z,1565386922.757 [SyncHandler](INFO): Protected caller Thread ID is 5179
2019-08-09T21:42:02.757Z,1565386922.757 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-09T21:42:02.758Z,1565386922.758 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-09T21:42:02.759Z,1565386922.759 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5180
2019-08-09T21:42:02.762Z,1565386922.762 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-09T21:42:02.774Z,1565386922.774 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-09T21:42:02.775Z,1565386922.775 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-09T21:42:02.775Z,1565386922.775 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5181
2019-08-09T21:42:02.776Z,1565386922.776 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-09T21:42:02.777Z,1565386922.777 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-09T21:42:02.777Z,1565386922.777 [logger ThreadHandler](INFO): Protected caller Thread ID is 5182
2019-08-09T21:42:02.779Z,1565386922.779 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-09T21:42:02.780Z,1565386922.780 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-09T21:42:02.781Z,1565386922.781 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-09T21:42:03.204Z,1565386923.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-09T21:42:03.205Z,1565386923.205 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-09T21:42:03.305Z,1565386923.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-09T21:42:03.306Z,1565386923.306 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-09T21:42:03.622Z,1565386923.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-09T21:42:03.623Z,1565386923.623 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-09T21:42:03.762Z,1565386923.762 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-09T21:42:03.762Z,1565386923.763 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-09T21:42:03.954Z,1565386923.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-09T21:42:03.954Z,1565386923.954 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-09T21:42:04.402Z,1565386924.402 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-09T21:42:04.402Z,1565386924.402 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-09T21:42:04.608Z,1565386924.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-09T21:42:04.609Z,1565386924.609 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-09T21:42:04.752Z,1565386924.752 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-09T21:42:04.752Z,1565386924.752 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-09T21:42:04.946Z,1565386924.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-09T21:42:04.946Z,1565386924.946 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-09T21:42:05.041Z,1565386925.041 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-09T21:42:05.042Z,1565386925.042 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-09T21:42:05.341Z,1565386925.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-09T21:42:05.342Z,1565386925.342 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-09T21:42:05.421Z,1565386925.421 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-09T21:42:05.523Z,1565386925.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-09T21:42:05.523Z,1565386925.523 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-09T21:42:06.116Z,1565386926.116 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-09T21:42:06.117Z,1565386926.117 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-09T21:42:06.515Z,1565386926.515 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-09T21:42:06.517Z,1565386926.517 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-08-09T21:42:06.518Z,1565386926.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-08-09T21:42:06.727Z,1565386926.727 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-08-09T21:42:06.826Z,1565386926.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-08-09T21:42:06.924Z,1565386926.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-08-09T21:42:07.308Z,1565386927.308 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-09T21:42:07.308Z,1565386927.308 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-08-09T21:42:07.407Z,1565386927.407 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-08-09T21:42:07.645Z,1565386927.645 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-08-09T21:42:07.773Z,1565386927.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-08-09T21:42:07.935Z,1565386927.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-08-09T21:42:08.121Z,1565386928.121 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-08-09T21:42:08.476Z,1565386928.476 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-08-09T21:42:08.657Z,1565386928.657 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-08-09T21:42:08.657Z,1565386928.657 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-09T21:42:08.667Z,1565386928.667 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-09T21:42:09.195Z,1565386929.195 [AHRS_M2] Loaded
2019-08-09T21:42:09.196Z,1565386929.196 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-08-09T21:42:09.270Z,1565386929.270 [DataOverHttps] Loaded
2019-08-09T21:42:09.270Z,1565386929.270 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-09T21:42:09.271Z,1565386929.271 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407664E0
2019-08-09T21:42:09.272Z,1565386929.272 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5261
2019-08-09T21:42:09.285Z,1565386929.285 [Depth_Keller] Loaded
2019-08-09T21:42:09.285Z,1565386929.285 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-09T21:42:09.290Z,1565386929.290 [DropWeight] Loaded
2019-08-09T21:42:09.290Z,1565386929.290 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-08-09T21:42:09.348Z,1565386929.348 [DUSBL_Hydroid] Loaded
2019-08-09T21:42:09.349Z,1565386929.349 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-08-09T21:42:09.398Z,1565386929.398 [Micromodem] Loaded
2019-08-09T21:42:09.398Z,1565386929.398 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-08-09T21:42:09.496Z,1565386929.496 [NAL9602] Loaded
2019-08-09T21:42:09.497Z,1565386929.497 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-09T21:42:09.513Z,1565386929.513 [Onboard] Loaded
2019-08-09T21:42:09.513Z,1565386929.513 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-09T21:42:09.519Z,1565386929.519 [PowerOnly] Loaded
2019-08-09T21:42:09.519Z,1565386929.519 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-08-09T21:42:09.526Z,1565386929.526 [Radio_Surface] Loaded
2019-08-09T21:42:09.526Z,1565386929.526 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-09T21:42:09.527Z,1565386929.527 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407964E0
2019-08-09T21:42:09.528Z,1565386929.528 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5262
2019-08-09T21:42:09.573Z,1565386929.573 [RDI_Pathfinder] Loaded
2019-08-09T21:42:09.573Z,1565386929.573 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-08-09T21:42:11.073Z,1565386931.073 [BPC1] Loaded
2019-08-09T21:42:11.073Z,1565386931.073 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-09T21:42:11.074Z,1565386931.074 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-09T21:42:11.074Z,1565386931.074 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-09T21:42:11.087Z,1565386931.087 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-09T21:42:11.088Z,1565386931.088 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-09T21:42:11.196Z,1565386931.196 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-09T21:42:11.196Z,1565386931.196 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-09T21:42:11.217Z,1565386931.217 [NavChart] Loaded
2019-08-09T21:42:11.217Z,1565386931.217 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-09T21:42:11.221Z,1565386931.221 [UniversalFixResidualReporter] Loaded
2019-08-09T21:42:11.221Z,1565386931.221 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-09T21:42:11.222Z,1565386931.222 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-09T21:42:11.222Z,1565386931.222 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-09T21:42:11.329Z,1565386931.329 [BuoyancyServo] Loaded
2019-08-09T21:42:11.329Z,1565386931.329 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-09T21:42:11.345Z,1565386931.345 [ElevatorServo] Loaded
2019-08-09T21:42:11.345Z,1565386931.345 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-09T21:42:11.360Z,1565386931.360 [MassServo] Loaded
2019-08-09T21:42:11.360Z,1565386931.360 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-09T21:42:11.375Z,1565386931.375 [RudderServo] Loaded
2019-08-09T21:42:11.376Z,1565386931.376 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-09T21:42:11.390Z,1565386931.390 [ThrusterServo] Loaded
2019-08-09T21:42:11.391Z,1565386931.391 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-09T21:42:11.391Z,1565386931.391 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-09T21:42:11.392Z,1565386931.392 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-09T21:42:11.641Z,1565386931.641 [CTD_NeilBrown] Loaded
2019-08-09T21:42:11.642Z,1565386931.642 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-08-09T21:42:11.643Z,1565386931.643 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E14E0
2019-08-09T21:42:11.643Z,1565386931.643 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 5263
2019-08-09T21:42:11.673Z,1565386931.673 [ESPComponent] Loaded
2019-08-09T21:42:11.674Z,1565386931.674 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-08-09T21:42:11.719Z,1565386931.719 [WetLabsSeaOWL_UV_A] Loaded
2019-08-09T21:42:11.719Z,1565386931.719 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-08-09T21:42:11.720Z,1565386931.720 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409114E0
2019-08-09T21:42:11.720Z,1565386931.720 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 5264
2019-08-09T21:42:11.721Z,1565386931.721 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-09T21:42:11.722Z,1565386931.722 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-09T21:42:12.012Z,1565386932.012 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-09T21:42:12.013Z,1565386932.013 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-09T21:42:12.054Z,1565386932.054 [DepthRateCalculator] Loaded
2019-08-09T21:42:12.055Z,1565386932.055 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-09T21:42:12.061Z,1565386932.061 [PitchRateCalculator] Loaded
2019-08-09T21:42:12.061Z,1565386932.061 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-09T21:42:12.074Z,1565386932.074 [SpeedCalculator] Loaded
2019-08-09T21:42:12.074Z,1565386932.074 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-09T21:42:12.095Z,1565386932.095 [TempGradientCalculator] Loaded
2019-08-09T21:42:12.096Z,1565386932.096 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-09T21:42:12.101Z,1565386932.101 [YawRateCalculator] Loaded
2019-08-09T21:42:12.102Z,1565386932.102 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-09T21:42:12.142Z,1565386932.142 [ElevatorOffsetCalculator] Loaded
2019-08-09T21:42:12.143Z,1565386932.143 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-09T21:42:12.143Z,1565386932.143 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-09T21:42:12.144Z,1565386932.144 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-09T21:42:12.276Z,1565386932.276 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-09T21:42:12.298Z,1565386932.298 [SBIT] Loaded
2019-08-09T21:42:12.299Z,1565386932.299 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-09T21:42:12.299Z,1565386932.299 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-09T21:42:12.311Z,1565386932.311 [IBIT] Loaded
2019-08-09T21:42:12.311Z,1565386932.311 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-09T21:42:12.314Z,1565386932.314 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-09T21:42:12.454Z,1565386932.454 [CBIT] Loaded
2019-08-09T21:42:12.455Z,1565386932.455 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-09T21:42:12.455Z,1565386932.455 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-09T21:42:12.456Z,1565386932.456 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-09T21:42:12.617Z,1565386932.617 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-09T21:42:12.617Z,1565386932.617 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-09T21:42:12.774Z,1565386932.774 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-09T21:42:12.774Z,1565386932.774 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-09T21:42:12.840Z,1565386932.840 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-09T21:42:12.926Z,1565386932.926 [VerticalControl] Loaded
2019-08-09T21:42:12.926Z,1565386932.926 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-09T21:42:12.927Z,1565386932.927 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-09T21:42:12.985Z,1565386932.985 [HorizontalControl] Loaded
2019-08-09T21:42:12.985Z,1565386932.985 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-09T21:42:12.986Z,1565386932.986 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-09T21:42:12.988Z,1565386932.988 [SpeedControl] Loaded
2019-08-09T21:42:12.988Z,1565386932.988 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-09T21:42:12.989Z,1565386932.989 [LoopControl](DEBUG): Construct LoopControl.
2019-08-09T21:42:12.989Z,1565386932.989 [LoopControl] Loaded
2019-08-09T21:42:12.990Z,1565386932.990 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-09T21:42:12.990Z,1565386932.990 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-09T21:42:12.991Z,1565386932.991 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-09T21:42:13.023Z,1565386933.023 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-09T21:42:13.026Z,1565386933.026 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-09T21:42:13.027Z,1565386933.027 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-09T21:42:13.034Z,1565386933.034 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-09T21:42:13.035Z,1565386933.035 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AED4E0
2019-08-09T21:42:13.035Z,1565386933.035 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5265
2019-08-09T21:42:13.040Z,1565386933.040 [Supervisor](INFO): Main Thread ID is 4140
2019-08-09T21:42:13.040Z,1565386933.040 [Supervisor](DEBUG): Running supervisor.
2019-08-09T21:42:13.041Z,1565386933.041 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5266
2019-08-09T21:42:13.043Z,1565386933.043 [controlThread ThreadHandler](INFO): Handler Thread ID is 5267
2019-08-09T21:42:13.043Z,1565386933.043 [controlThread](DEBUG): Initializing ControlThread
2019-08-09T21:42:13.052Z,1565386933.052 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-09T21:42:13.052Z,1565386933.052 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-09T21:42:13.054Z,1565386933.054 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-09T21:42:13.054Z,1565386933.054 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-09T21:42:13.055Z,1565386933.055 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-09T21:42:13.055Z,1565386933.055 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-09T21:42:13.056Z,1565386933.056 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-09T21:42:13.056Z,1565386933.056 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-09T21:42:13.057Z,1565386933.057 [SBIT](INFO): Initialize SBIT Component.
2019-08-09T21:42:13.057Z,1565386933.057 [SBIT](IMPORTANT): git: 2019-07-16A-4-gbc3a532
2019-08-09T21:42:13.057Z,1565386933.057 [SBIT](INFO): git hash: bc3a532330c34a530d393d20f0a16563b6db3de2
2019-08-09T21:42:13.058Z,1565386933.058 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-09T21:42:13.059Z,1565386933.059 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2019-08-09T21:42:13.060Z,1565386933.060 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-08-09T21:42:13.061Z,1565386933.061 [IBIT](INFO): Initialize IBIT Component.
2019-08-09T21:42:13.061Z,1565386933.061 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-09T21:42:13.062Z,1565386933.062 [logger ThreadHandler](INFO): Handler Thread ID is 5268
2019-08-09T21:42:13.072Z,1565386933.072 [CBIT](DEBUG): Initialized mux pins.
2019-08-09T21:42:13.073Z,1565386933.073 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-09T21:42:13.081Z,1565386933.081 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5269
2019-08-09T21:42:13.082Z,1565386933.082 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-09T21:42:13.093Z,1565386933.093 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5270
2019-08-09T21:42:13.097Z,1565386933.097 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-08-09T21:42:13.097Z,1565386933.097 [CBIT](DEBUG): Initializing heartbeat.
2019-08-09T21:42:13.113Z,1565386933.113 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 5271
2019-08-09T21:42:13.114Z,1565386933.114 [CTD_NeilBrown](INFO): Powering down
2019-08-09T21:42:13.141Z,1565386933.141 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 5272
2019-08-09T21:42:13.142Z,1565386933.142 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-08-09T21:42:13.168Z,1565386933.168 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-09T21:42:13.169Z,1565386933.169 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-09T21:42:13.173Z,1565386933.173 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5273
2019-08-09T21:42:13.176Z,1565386933.176 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-09T21:42:13.176Z,1565386933.176 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-09T21:42:13.177Z,1565386933.177 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-09T21:42:13.177Z,1565386933.177 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-09T21:42:13.177Z,1565386933.177 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-09T21:42:13.177Z,1565386933.177 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-09T21:42:13.177Z,1565386933.177 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-09T21:42:13.177Z,1565386933.177 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-09T21:42:13.178Z,1565386933.178 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-09T21:42:13.178Z,1565386933.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-09T21:42:13.178Z,1565386933.178 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-09T21:42:13.178Z,1565386933.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-09T21:42:13.178Z,1565386933.178 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-09T21:42:13.178Z,1565386933.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-09T21:42:13.179Z,1565386933.179 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-09T21:42:13.179Z,1565386933.179 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-09T21:42:13.205Z,1565386933.205 [CBIT](DEBUG): Backplane powered.
2019-08-09T21:42:13.205Z,1565386933.205 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-09T21:42:13.207Z,1565386933.207 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-09T21:42:13.207Z,1565386933.207 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-09T21:42:13.208Z,1565386933.208 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-09T21:42:13.209Z,1565386933.209 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-09T21:42:13.219Z,1565386933.219 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-09T21:42:13.250Z,1565386933.250 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2019-08-09T21:42:13.251Z,1565386933.251 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-09T21:42:13.320Z,1565386933.320 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-09T21:42:13.321Z,1565386933.321 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-09T21:42:13.323Z,1565386933.323 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-09T21:42:13.368Z,1565386933.368 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-09T21:42:13.379Z,1565386933.379 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-09T21:42:13.405Z,1565386933.405 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-09T21:42:13.415Z,1565386933.415 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-08-09T21:42:13.420Z,1565386933.420 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,ESPComponent,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-08-09T21:42:13.437Z,1565386933.437 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-08-09T21:42:13.486Z,1565386933.486 [DUSBL_Hydroid](INFO): Powering up
2019-08-09T21:42:13.486Z,1565386933.486 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-08-09T21:42:13.497Z,1565386933.497 [Radio_Surface](INFO): Powering up
2019-08-09T21:42:13.594Z,1565386933.594 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-09T21:42:13.601Z,1565386933.601 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-09T21:42:13.602Z,1565386933.602 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-09T21:42:13.609Z,1565386933.609 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-09T21:42:13.610Z,1565386933.610 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-09T21:42:13.617Z,1565386933.617 [MassServo](DEBUG): Initializing MassServo.
2019-08-09T21:42:13.629Z,1565386933.629 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-09T21:42:13.637Z,1565386933.637 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-09T21:42:13.638Z,1565386933.638 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-09T21:42:13.645Z,1565386933.645 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-09T21:42:13.843Z,1565386933.843 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-08-09T21:42:13.843Z,1565386933.843 [DropWeight] Hardware Fault, FailCount= 1
2019-08-09T21:42:13.843Z,1565386933.843 [DropWeight](ERROR): Hardware Fault
2019-08-09T21:42:13.845Z,1565386933.845 [Micromodem](INFO): Powering up
2019-08-09T21:42:13.845Z,1565386933.845 [Micromodem](DEBUG): Initializing Micromodem.
2019-08-09T21:42:13.890Z,1565386933.890 [CommandLine](FAULT): Scheduling is paused
2019-08-09T21:42:13.890Z,1565386933.890 [CBIT](INFO): Critical error at 20190809T214213
2019-08-09T21:42:13.891Z,1565386933.891 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-08-09T21:42:13.893Z,1565386933.893 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-08-09T21:42:13.894Z,1565386933.894 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-08-09T21:42:14.589Z,1565386934.589 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-08-09T21:42:14.589Z,1565386934.589 [RudderServo](FAULT): Rudder failed to initialize
2019-08-09T21:42:14.589Z,1565386934.589 [RudderServo] Communications Fault, FailCount= 1
2019-08-09T21:42:14.589Z,1565386934.589 [RudderServo](ERROR): Communications Fault
2019-08-09T21:42:14.698Z,1565386934.698 [CBIT](INFO): Critical error at 20190809T214213
2019-08-09T21:42:14.701Z,1565386934.701 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-08-09T21:42:14.866Z,1565386934.866 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-09T21:42:14.866Z,1565386934.866 [RudderServo](INFO): Powering down
2019-08-09T21:42:15.544Z,1565386935.544 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-09T21:42:15.665Z,1565386935.665 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-09T21:42:15.670Z,1565386935.670 [CBIT](INFO): Clearing failed state for component RudderServo
2019-08-09T21:42:15.670Z,1565386935.670 [RudderServo] No Fault, FailCount= 1
2019-08-09T21:42:18.788Z,1565386938.788 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-08-09T21:42:19.191Z,1565386939.191 [Micromodem](INFO): Nmea in: $CATMG,2019-08-09T21:42:18.674893Z,RTC,RTC*50

2019-08-09T21:42:19.192Z,1565386939.192 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-08-09T21:42:18.674893Z,RTC,RTC*50

2019-08-09T21:42:19.690Z,1565386939.690 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-08-09T21:42:19.691Z,1565386939.691 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-08-09T21:42:20.090Z,1565386940.090 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-08-09T21:42:20.091Z,1565386940.091 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-08-09T21:42:20.483Z,1565386940.483 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-08-09T21:42:20.483Z,1565386940.483 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2019-08-09T21:42:20.899Z,1565386940.899 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2019-08-09T21:42:20.899Z,1565386940.899 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2019-08-09T21:42:21.302Z,1565386941.302 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2019-08-09T21:42:21.303Z,1565386941.303 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2019-08-09T21:42:21.695Z,1565386941.695 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2019-08-09T21:42:21.695Z,1565386941.695 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2019-08-09T21:42:22.096Z,1565386942.096 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2019-08-09T21:42:22.096Z,1565386942.096 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2019-08-09T21:42:22.490Z,1565386942.490 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2019-08-09T21:42:22.491Z,1565386942.491 [Micromodem](INFO): Nmea out: $CCCLK,2019,08,09,21,42,23*4B

2019-08-09T21:42:22.903Z,1565386942.903 [Micromodem](INFO): Nmea in: $CACLK,2019,8,9,21,42,23*49

2019-08-09T21:42:23.295Z,1565386943.295 [Micromodem](INFO): Nmea in: $CATMS,0,2019-08-09T21:42:24Z*7E

2019-08-09T21:42:23.296Z,1565386943.296 [Micromodem](INFO): Nmea in: $CATMG,2019-08-09T21:42:24.027080Z,USER_CMD,RTC*14

2019-08-09T21:42:26.952Z,1565386946.952 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-08-09T21:42:31.374Z,1565386951.374 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-08-09T21:42:39.855Z,1565386959.855 [NAL9602](INFO): Powering up NAL9602
2019-08-09T21:42:41.515Z,1565386961.515 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-09T21:42:41.523Z,1565386961.523 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-09T21:42:50.066Z,1565386970.066 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-08-09T21:42:50.067Z,1565386970.067 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19080914503025,35.0, -0.1,   0.0,1448.9,, 94.92,  95.92,  95.92,   0.00
2019-08-09T21:42:50.839Z,1565386970.839 [NAL9602](INFO): NAL9602 initialized
2019-08-09T21:42:51.681Z,1565386971.681 [NAL9602](DEBUG): Fix Requested
2019-08-09T21:42:52.585Z,1565386972.585 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010074
CHAN A1 (24V): -0.027623
CHAN A2 (12V): -0.006935
CHAN A3 (5V): -0.002254
CHAN B0 (3.3V): 0.000101
CHAN B1 (3.15aV): 0.000052
CHAN B2 (3.15bV): -0.000054
CHAN B3 (GND): 0.002142
OPEN: 0.006921
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-09T21:43:00.675Z,1565386980.675 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-08-09T21:43:00.675Z,1565386980.675 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19080914504125,35.0, -0.1,   0.0,1448.9,,  0.00,  94.92,  94.92,  95.92,   0.00
2019-08-09T21:43:35.215Z,1565387015.215 [SBIT](IMPORTANT): SBIT PASSED
2019-08-09T21:43:35.255Z,1565387015.255 [CommandLine](IMPORTANT): got command configSet list
2019-08-09T21:43:35.256Z,1565387015.256 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-09T21:43:35.257Z,1565387015.257 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=10 count;

2019-08-09T21:43:35.257Z,1565387015.257 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2019-08-09T21:43:35.257Z,1565387015.257 [CommandLine](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2019-08-09T21:43:35.258Z,1565387015.258 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2019-08-09T21:43:35.258Z,1565387015.258 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 2.000000 meter;

2019-08-09T21:43:35.258Z,1565387015.258 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none;

2019-08-09T21:43:35.258Z,1565387015.258 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree;

2019-08-09T21:43:35.258Z,1565387015.258 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold=2 meter;

2019-08-09T21:43:35.258Z,1565387015.258 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-09T21:43:35.609Z,1565387015.609 [MissionManager](IMPORTANT): Started mission Startup
2019-08-09T21:43:35.610Z,1565387015.610 [Startup] Running Loop=1
2019-08-09T21:43:35.610Z,1565387015.610 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-09T21:43:35.610Z,1565387015.610 [Startup:A.GoToSurface] Running Loop=1
2019-08-09T21:43:35.610Z,1565387015.610 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-09T21:43:35.610Z,1565387015.610 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-09T21:43:35.611Z,1565387015.611 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-09T21:43:35.611Z,1565387015.611 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-09T21:43:35.612Z,1565387015.612 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-09T21:43:35.612Z,1565387015.612 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-09T21:43:35.613Z,1565387015.613 [Startup:StartupSatComms] Running Loop=1
2019-08-09T21:43:35.614Z,1565387015.614 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-09T21:43:35.614Z,1565387015.614 [Startup:StartupSatComms:A] Running Loop=1
2019-08-09T21:43:36.030Z,1565387016.030 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-09T21:44:06.272Z,1565387046.272 [NAL9602](INFO): SBD MO Status=2, MOMSN=8311, MT Status=2, MTMSN=0
2019-08-09T21:44:06.272Z,1565387046.272 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-09T21:44:29.697Z,1565387069.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=8311, MT Status=2, MTMSN=0
2019-08-09T21:44:29.697Z,1565387069.697 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-09T21:44:35.829Z,1565387075.829 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-09T21:43:35.6Z
2019-08-09T21:44:35.829Z,1565387075.829 [Startup:StartupSatComms:A] Stopped
2019-08-09T21:44:35.829Z,1565387075.829 [Startup:StartupSatComms:B] Running Loop=1
2019-08-09T21:44:36.186Z,1565387076.186 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-09T21:44:39.487Z,1565387079.487 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005007
2019-08-09T21:44:47.796Z,1565387087.796 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20190809T213749/Courier0004.lzma
2019-08-09T21:44:48.602Z,1565387088.602 [DataOverHttps](INFO): Moved sent file to Logs/20190809T213749/Courier0004.lzma.bak
2019-08-09T21:44:48.602Z,1565387088.602 [DataOverHttps](INFO): SBD MOMSN=11548996
2019-08-09T21:45:01.804Z,1565387101.804 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20190809T214202/Courier0000.lzma
2019-08-09T21:45:02.610Z,1565387102.610 [DataOverHttps](INFO): Moved sent file to Logs/20190809T214202/Courier0000.lzma.bak
2019-08-09T21:45:02.610Z,1565387102.610 [DataOverHttps](INFO): SBD MOMSN=11548998
2019-08-09T21:45:13.154Z,1565387113.154 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-09T21:45:13.155Z,1565387113.155 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-09T21:45:13.177Z,1565387113.177 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-09T21:45:13.477Z,1565387113.477 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-09T21:45:13.477Z,1565387113.477 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-09T21:45:13.598Z,1565387113.598 [DataOverHttps](INFO): Sending 886 bytes from file Logs/20190809T213749/Express0001.lzma
2019-08-09T21:45:14.402Z,1565387114.402 [DataOverHttps](INFO): Moved sent file to Logs/20190809T213749/Express0001.lzma.bak
2019-08-09T21:45:14.402Z,1565387114.402 [DataOverHttps](INFO): SBD MOMSN=11549003
2019-08-09T21:45:17.057Z,1565387117.057 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-08-09T21:45:17.057Z,1565387117.057 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,  94.92,   0.00
2019-08-09T21:45:25.437Z,1565387125.437 [DataOverHttps](INFO): Sending 279 bytes from file Logs/20190809T213749/Express0005.lzma
2019-08-09T21:45:26.238Z,1565387126.238 [DataOverHttps](INFO): Moved sent file to Logs/20190809T213749/Express0005.lzma.bak
2019-08-09T21:45:26.238Z,1565387126.238 [DataOverHttps](INFO): SBD MOMSN=11549026
2019-08-09T21:45:36.083Z,1565387136.083 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-09T21:44:35.8Z
2019-08-09T21:45:36.083Z,1565387136.083 [Startup:StartupSatComms:B] Stopped
2019-08-09T21:45:36.084Z,1565387136.084 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-09T21:45:36.084Z,1565387136.084 [Startup:StartupSatComms] Stopped
2019-08-09T21:45:36.084Z,1565387136.084 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-09T21:45:36.089Z,1565387136.089 [Startup](INFO): Completed Startup
2019-08-09T21:45:36.089Z,1565387136.089 [MissionManager](INFO): Startup is completed.
2019-08-09T21:45:36.089Z,1565387136.089 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-09T21:45:36.089Z,1565387136.089 [Startup] Stopped
2019-08-09T21:45:36.089Z,1565387136.089 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-09T21:45:36.089Z,1565387136.089 [Startup:A.GoToSurface] Stopped
2019-08-09T21:45:36.090Z,1565387136.089 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-09T21:45:36.438Z,1565387136.438 [MissionManager](IMPORTANT): Started mission Default
2019-08-09T21:45:36.438Z,1565387136.438 [Default] Running Loop=1
2019-08-09T21:45:36.438Z,1565387136.438 [Default](DEBUG): Aggregate::initialize Default
2019-08-09T21:45:36.438Z,1565387136.438 [Default:B.GoToSurface] Running Loop=1
2019-08-09T21:45:36.438Z,1565387136.438 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-09T21:45:36.438Z,1565387136.438 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-09T21:45:36.439Z,1565387136.439 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-09T21:45:36.439Z,1565387136.439 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-09T21:45:36.439Z,1565387136.439 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-09T21:45:36.440Z,1565387136.440 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-09T21:45:36.440Z,1565387136.440 [Default:A.Wait] Running Loop=1
2019-08-09T21:45:36.440Z,1565387136.440 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-09T21:45:37.473Z,1565387137.473 [DataOverHttps](INFO): Sending 881 bytes from file Logs/20190809T214202/Express0001.lzma
2019-08-09T21:45:38.278Z,1565387138.278 [DataOverHttps](INFO): Moved sent file to Logs/20190809T214202/Express0001.lzma.bak
2019-08-09T21:45:38.278Z,1565387138.278 [DataOverHttps](INFO): SBD MOMSN=11549038
2019-08-09T21:45:48.405Z,1565387148.405 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-08-09T21:45:48.406Z,1565387148.406 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-08-09T21:45:48.480Z,1565387148.480 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-08-09T21:45:48.484Z,1565387148.484 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-08-09T21:45:48.518Z,1565387148.518 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-08-09T21:45:48.542Z,1565387148.542 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-08-09T21:45:48.585Z,1565387148.585 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-08-09T21:45:48.586Z,1565387148.586 [DUSBL:A.Pitch](DEBUG): Construct.
2019-08-09T21:45:48.659Z,1565387148.659 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-08-09T21:45:48.693Z,1565387148.693 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-08-09T21:45:48.698Z,1565387148.698 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

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

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

    <DefineArg Name="NumberOfRequests"><Description>
        Number of pings to requst.
    </Description><Units:count/><Value>10</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>   

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>      
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

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

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

    <ReadData>
        <When>
            <Arg Name="EnabledDUSBL"/>
        </When>
            <Universal:acoustic_contact_range/>
            <Universal:acoustic_contact_direction_vehicle_frame/>
    </ReadData>
    
      <Aggregate Id="RequestRepeater">

        <Sequence Repeat="NumberOfRequests"/>
        <Assign><Parallel/><Sensor:DUSBL_Hydroid.transponderCode/><Arg Name="TransponderCode"/></Assign>
        <Assign><Parallel/><Sensor:DUSBL_Hydroid.pingRequested/><Arg Name="NumberOfPings"/></Assign>
          <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:second/><Value>90</Value></Setting>
          </Guidance:Wait>
      </Aggregate>    
</Mission>


2019-08-09T21:45:48.700Z,1565387148.700 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-08-09T21:45:48.983Z,1565387148.983 [Default] Stopped
2019-08-09T21:45:48.983Z,1565387148.983 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-09T21:45:48.983Z,1565387148.983 [Default:A.Wait] Stopped
2019-08-09T21:45:48.983Z,1565387148.983 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T21:45:48.983Z,1565387148.983 [Default:B.GoToSurface] Stopped
2019-08-09T21:45:48.983Z,1565387148.983 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-09T21:45:48.983Z,1565387148.983 [MissionManager](IMPORTANT): Started mission DUSBL
2019-08-09T21:45:48.984Z,1565387148.984 [DUSBL] Running Loop=1
2019-08-09T21:45:48.984Z,1565387148.984 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-08-09T21:45:48.984Z,1565387148.984 [DUSBL:A.Pitch] Running Loop=1
2019-08-09T21:45:48.984Z,1565387148.984 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:B.SetSpeed] Running Loop=1
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:C] Running Loop=1
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:RequestRepeater] Running Loop=1
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-08-09T21:45:48.985Z,1565387148.985 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T21:45:48.986Z,1565387148.986 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T21:45:48.986Z,1565387148.986 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T21:45:48.987Z,1565387148.987 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-08-09T21:45:48.987Z,1565387148.987 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-08-09T21:45:48.988Z,1565387148.988 [DUSBL:B.SetSpeed] Running Loop=1
2019-08-09T21:45:48.988Z,1565387148.988 [DUSBL:A.Pitch] Running Loop=1
2019-08-09T21:45:50.558Z,1565387150.558 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:45:50.558Z,1565387150.558 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:45:50.558Z,1565387150.558 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:45:50.559Z,1565387150.559 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:45:50.954Z,1565387150.954 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
O
2019-08-09T21:45:50.954Z,1565387150.954 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:45:50.954Z,1565387150.954 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:45:50.956Z,1565387150.956 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:45:51.371Z,1565387151.371 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:45:51.770Z,1565387151.770 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FAE,000,00038,184,80,80,0C,FF
2019-08-09T21:45:51.771Z,1565387151.771 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:45:54.286Z,1565387154.286 [Micromodem](INFO): Nmea in: $SNTTA,0.369864,,,,214551.99*40

2019-08-09T21:45:54.562Z,1565387154.562 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:45:54.562Z,1565387154.562 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:45:54.562Z,1565387154.562 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:45:54.563Z,1565387154.563 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:45:54.580Z,1565387154.580 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FAE,000,00038,184,80,80,0C,FF
2019-08-09T21:45:54.581Z,1565387154.581 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:45:54.581Z,1565387154.581 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:45:54.583Z,1565387154.583 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:45:54.913Z,1565387154.913 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:45:55.314Z,1565387155.314 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,001,000,0005E,183,80,80,0A,FF
2019-08-09T21:45:55.315Z,1565387155.315 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:45:57.829Z,1565387157.829 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214555.62*58

2019-08-09T21:45:58.006Z,1565387158.006 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:45:58.006Z,1565387158.006 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:45:58.007Z,1565387158.007 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:45:58.007Z,1565387158.007 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:45:58.350Z,1565387158.350 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
001,000,0005E,183,80,80,0A,FF
2019-08-09T21:45:58.350Z,1565387158.350 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:45:58.350Z,1565387158.350 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:45:58.351Z,1565387158.351 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:45:58.761Z,1565387158.761 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:45:59.154Z,1565387159.154 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,114,000,0006C,186,80,80,07,FF
2019-08-09T21:45:59.154Z,1565387159.154 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:01.672Z,1565387161.672 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214559.39*5A

2019-08-09T21:46:01.810Z,1565387161.810 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:01.810Z,1565387161.810 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:01.810Z,1565387161.810 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:01.811Z,1565387161.811 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:02.174Z,1565387162.174 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
114,000,0006C,186,80,80,07,FF
2019-08-09T21:46:02.174Z,1565387162.174 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:02.174Z,1565387162.174 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:02.176Z,1565387162.176 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:02.591Z,1565387162.591 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:02.985Z,1565387162.985 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,056,000,0011A,184,80,80,04,FF
2019-08-09T21:46:02.986Z,1565387162.986 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:05.501Z,1565387165.501 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214603.21*5F

2019-08-09T21:46:05.636Z,1565387165.636 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:05.638Z,1565387165.638 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:05.639Z,1565387165.639 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:05.640Z,1565387165.640 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:05.974Z,1565387165.974 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
056,000,0011A,184,80,80,04,FF
2019-08-09T21:46:05.974Z,1565387165.974 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:05.974Z,1565387165.974 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:05.976Z,1565387165.976 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:06.381Z,1565387166.381 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:06.778Z,1565387166.778 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,136,000,0006C,187,80,80,06,FF
2019-08-09T21:46:06.778Z,1565387166.778 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:09.294Z,1565387169.293 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214607.01*59

2019-08-09T21:46:09.426Z,1565387169.426 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:09.426Z,1565387169.426 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:09.426Z,1565387169.426 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:09.427Z,1565387169.427 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:09.777Z,1565387169.777 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
136,000,0006C,187,80,80,06,FF
2019-08-09T21:46:09.777Z,1565387169.777 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:09.777Z,1565387169.777 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:09.778Z,1565387169.778 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:10.177Z,1565387170.177 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:10.582Z,1565387170.582 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FBB,000,0005A,184,80,80,05,FF
2019-08-09T21:46:10.582Z,1565387170.582 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:13.098Z,1565387173.098 [Micromodem](INFO): Nmea in: $SNTTA,0.326028,,,,214610.82*47

2019-08-09T21:46:13.271Z,1565387173.271 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:13.272Z,1565387173.272 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:13.272Z,1565387173.272 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:13.273Z,1565387173.273 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:13.636Z,1565387173.636 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FBB,000,0005A,184,80,80,05,FF
2019-08-09T21:46:13.637Z,1565387173.637 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:13.637Z,1565387173.637 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:13.642Z,1565387173.642 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:14.041Z,1565387174.041 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:14.438Z,1565387174.438 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,013,000,0005E,183,80,80,0A,FF
2019-08-09T21:46:14.438Z,1565387174.438 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:16.954Z,1565387176.954 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214614.68*54

2019-08-09T21:46:17.145Z,1565387177.145 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:17.145Z,1565387177.145 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:17.145Z,1565387177.145 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:17.146Z,1565387177.146 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:17.482Z,1565387177.482 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
013,000,0005E,183,80,80,0A,FF
2019-08-09T21:46:17.482Z,1565387177.482 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:17.482Z,1565387177.482 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:17.483Z,1565387177.483 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:17.889Z,1565387177.889 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:18.298Z,1565387178.298 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,102,000,0008B,187,80,80,03,FF
2019-08-09T21:46:18.298Z,1565387178.298 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:20.814Z,1565387180.814 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214618.52*51

2019-08-09T21:46:20.979Z,1565387180.979 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:20.979Z,1565387180.979 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:20.979Z,1565387180.979 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:20.980Z,1565387180.980 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:21.306Z,1565387181.306 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
102,000,0008B,187,80,80,03,FF
2019-08-09T21:46:21.306Z,1565387181.306 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:21.306Z,1565387181.306 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:21.307Z,1565387181.307 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:21.717Z,1565387181.717 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:22.118Z,1565387182.118 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,102,000,00174,186,80,80,06,FF
2019-08-09T21:46:22.118Z,1565387182.118 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:24.637Z,1565387184.637 [Micromodem](INFO): Nmea in: $SNTTA,0.401137,,,,214622.34*46

2019-08-09T21:46:24.825Z,1565387184.825 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:24.825Z,1565387184.825 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:24.826Z,1565387184.826 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:24.826Z,1565387184.826 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:25.154Z,1565387185.154 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
102,000,00174,186,80,80,06,FF
2019-08-09T21:46:25.154Z,1565387185.154 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:25.154Z,1565387185.154 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:25.156Z,1565387185.156 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:25.557Z,1565387185.557 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:25.975Z,1565387185.975 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,12D,000,0006C,186,80,80,05,FF
2019-08-09T21:46:25.989Z,1565387185.989 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:28.505Z,1565387188.505 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214626.19*53

2019-08-09T21:46:28.849Z,1565387188.849 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:28.850Z,1565387188.850 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:28.850Z,1565387188.850 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:28.851Z,1565387188.851 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:29.202Z,1565387189.202 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
12D,000,0006C,186,80,80,05,FF
2019-08-09T21:46:29.202Z,1565387189.202 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:29.203Z,1565387189.203 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:29.204Z,1565387189.204 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:29.613Z,1565387189.613 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:30.014Z,1565387190.014 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FA4,000,00039,186,80,80,0B,FF
2019-08-09T21:46:30.014Z,1565387190.014 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:32.530Z,1565387192.530 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214630.24*5A

2019-08-09T21:46:32.677Z,1565387192.677 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:32.677Z,1565387192.677 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:32.677Z,1565387192.677 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:32.678Z,1565387192.678 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:33.018Z,1565387193.018 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FA4,000,00039,186,80,80,0B,FF
2019-08-09T21:46:33.018Z,1565387193.018 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:33.018Z,1565387193.018 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:33.019Z,1565387193.019 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:33.417Z,1565387193.417 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:33.826Z,1565387193.826 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FF6,000,0005A,183,80,80,04,FF
2019-08-09T21:46:33.826Z,1565387193.826 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:36.342Z,1565387196.342 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214634.05*5D

2019-08-09T21:46:36.473Z,1565387196.473 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:36.474Z,1565387196.474 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:36.474Z,1565387196.474 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:36.475Z,1565387196.475 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:36.846Z,1565387196.846 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FF6,000,0005A,183,80,80,04,FF
2019-08-09T21:46:36.846Z,1565387196.846 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:36.846Z,1565387196.846 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:36.848Z,1565387196.848 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:37.241Z,1565387197.241 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:38.045Z,1565387198.045 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214637.88*5B

2019-08-09T21:46:42.497Z,1565387202.497 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.022040
2019-08-09T21:46:42.497Z,1565387202.497 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:42.497Z,1565387202.497 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:42.497Z,1565387202.497 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:42.498Z,1565387202.498 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:42.902Z,1565387202.902 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FF6,000,0005A,183,80,80,04,FF
2019-08-09T21:46:42.902Z,1565387202.902 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:42.902Z,1565387202.902 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:42.904Z,1565387202.904 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:43.313Z,1565387203.313 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:43.695Z,1565387203.695 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FE4,000,00059,185,80,80,05,FF
2019-08-09T21:46:43.695Z,1565387203.695 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:46.209Z,1565387206.209 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214643.94*55

2019-08-09T21:46:46.357Z,1565387206.357 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:46.358Z,1565387206.358 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:46.358Z,1565387206.358 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:46.359Z,1565387206.359 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:46.710Z,1565387206.710 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FE4,000,00059,185,80,80,05,FF
2019-08-09T21:46:46.710Z,1565387206.710 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:46.710Z,1565387206.710 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:46.711Z,1565387206.711 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:47.109Z,1565387207.109 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:47.520Z,1565387207.520 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,100,000,0006C,186,80,80,06,FF
2019-08-09T21:46:47.520Z,1565387207.520 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:50.038Z,1565387210.038 [Micromodem](INFO): Nmea in: $SNTTA,0.231504,,,,214647.75*41

2019-08-09T21:46:50.177Z,1565387210.177 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:50.177Z,1565387210.177 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:50.178Z,1565387210.178 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:50.179Z,1565387210.179 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:50.558Z,1565387210.558 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
100,000,0006C,186,80,80,06,FF
2019-08-09T21:46:50.558Z,1565387210.558 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:50.558Z,1565387210.558 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:50.560Z,1565387210.560 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:50.965Z,1565387210.965 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:51.370Z,1565387211.370 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FAF,000,00039,184,80,80,0C,FF
2019-08-09T21:46:51.370Z,1565387211.370 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:53.886Z,1565387213.886 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214651.60*5D

2019-08-09T21:46:54.106Z,1565387214.106 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:54.106Z,1565387214.106 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:54.106Z,1565387214.106 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:54.107Z,1565387214.107 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:54.458Z,1565387214.458 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FAF,000,00039,184,80,80,0C,FF
2019-08-09T21:46:54.458Z,1565387214.458 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:54.458Z,1565387214.458 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:54.459Z,1565387214.459 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:54.861Z,1565387214.861 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:55.262Z,1565387215.262 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,01F,000,0005E,185,80,80,06,FF
2019-08-09T21:46:55.262Z,1565387215.262 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:46:57.778Z,1565387217.778 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214655.49*52

2019-08-09T21:46:57.941Z,1565387217.941 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:46:57.942Z,1565387217.942 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:46:57.942Z,1565387217.942 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:46:57.942Z,1565387217.942 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:46:58.282Z,1565387218.282 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
01F,000,0005E,185,80,80,06,FF
2019-08-09T21:46:58.282Z,1565387218.282 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:46:58.282Z,1565387218.282 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:46:58.284Z,1565387218.284 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:46:58.685Z,1565387218.685 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:46:59.086Z,1565387219.086 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,00C,000,0005E,183,80,80,08,FF
2019-08-09T21:46:59.086Z,1565387219.086 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:01.602Z,1565387221.602 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214659.32*52

2019-08-09T21:47:01.782Z,1565387221.782 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:47:01.782Z,1565387221.782 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:47:01.782Z,1565387221.782 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:47:01.783Z,1565387221.783 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:47:02.142Z,1565387222.142 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
00C,000,0005E,183,80,80,08,FF
2019-08-09T21:47:02.142Z,1565387222.142 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:47:02.142Z,1565387222.142 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:47:02.143Z,1565387222.143 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:47:02.541Z,1565387222.541 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:47:02.950Z,1565387222.950 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,003,000,0005E,183,80,80,0A,FF
2019-08-09T21:47:02.950Z,1565387222.950 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:05.466Z,1565387225.466 [Micromodem](INFO): Nmea in: $SNTTA,0.318741,,,,214703.18*42

2019-08-09T21:47:05.590Z,1565387225.590 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:47:05.590Z,1565387225.590 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:47:05.590Z,1565387225.590 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:47:05.591Z,1565387225.591 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:47:05.970Z,1565387225.970 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
003,000,0005E,183,80,80,0A,FF
2019-08-09T21:47:05.970Z,1565387225.970 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:47:05.970Z,1565387225.970 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:47:05.972Z,1565387225.972 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:47:06.369Z,1565387226.369 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:47:06.770Z,1565387226.770 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FA4,000,00039,186,80,80,0C,FF
2019-08-09T21:47:06.770Z,1565387226.770 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:09.286Z,1565387229.286 [Micromodem](INFO): Nmea in: $SNTTA,0.303405,,,,214707.01*47

2019-08-09T21:47:09.453Z,1565387229.453 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:47:09.454Z,1565387229.454 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:47:09.454Z,1565387229.454 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:47:09.455Z,1565387229.455 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:47:09.814Z,1565387229.814 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FA4,000,00039,186,80,80,0C,FF
2019-08-09T21:47:09.814Z,1565387229.814 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:47:09.815Z,1565387229.815 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:47:09.816Z,1565387229.816 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:47:10.217Z,1565387230.217 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:47:10.619Z,1565387230.619 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FA2,000,00038,187,80,80,0C,FF
2019-08-09T21:47:10.620Z,1565387230.620 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:13.134Z,1565387233.134 [Micromodem](INFO): Nmea in: $SNTTA,0.401191,,,,214710.85*40

2019-08-09T21:47:13.277Z,1565387233.277 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:47:13.278Z,1565387233.278 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:47:13.278Z,1565387233.278 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:47:13.278Z,1565387233.278 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:47:13.672Z,1565387233.672 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FA2,000,00038,187,80,80,0C,FF
2019-08-09T21:47:13.672Z,1565387233.672 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:47:13.673Z,1565387233.673 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:47:13.674Z,1565387233.674 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:47:14.057Z,1565387234.057 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:47:14.478Z,1565387234.478 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FAA,000,00038,184,80,80,0C,FF
2019-08-09T21:47:14.478Z,1565387234.478 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:16.994Z,1565387236.994 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214714.71*5D

2019-08-09T21:47:17.188Z,1565387237.188 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:47:17.188Z,1565387237.188 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:47:17.188Z,1565387237.188 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:47:17.197Z,1565387237.197 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:47:17.534Z,1565387237.534 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
FAA,000,00038,184,80,80,0C,FF
2019-08-09T21:47:17.534Z,1565387237.534 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:47:17.534Z,1565387237.534 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:47:17.535Z,1565387237.535 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:47:17.941Z,1565387237.941 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:47:18.350Z,1565387238.350 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,001,000,0005E,183,80,80,0A,FF
2019-08-09T21:47:18.350Z,1565387238.350 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:20.866Z,1565387240.866 [Micromodem](INFO): Nmea in: $SNTTA,0.399798,,,,214718.57*4E

2019-08-09T21:47:21.009Z,1565387241.009 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-08-09T21:47:21.009Z,1565387241.009 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-08-09T21:47:21.009Z,1565387241.009 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T21:47:21.010Z,1565387241.010 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-08-09T21:47:21.010Z,1565387241.010 [DUSBL:RequestRepeater] Stopped
2019-08-09T21:47:21.010Z,1565387241.010 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-08-09T21:47:21.010Z,1565387241.010 [DUSBL:RequestRepeater:A] Stopped
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater:B] Stopped
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater] Running Loop=2
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-08-09T21:47:21.011Z,1565387241.011 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T21:47:21.083Z,1565387241.083 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:47:21.083Z,1565387241.083 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:47:21.083Z,1565387241.083 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:47:21.084Z,1565387241.084 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:47:21.438Z,1565387241.438 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
001,000,0005E,183,80,80,0A,FF
2019-08-09T21:47:21.438Z,1565387241.438 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:47:21.438Z,1565387241.438 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:47:21.440Z,1565387241.440 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:47:21.841Z,1565387241.841 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:47:22.242Z,1565387242.242 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,13A,000,00173,186,80,80,05,FF
2019-08-09T21:47:22.242Z,1565387242.242 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:24.758Z,1565387244.758 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214722.47*5D

2019-08-09T21:47:24.949Z,1565387244.949 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T21:47:24.950Z,1565387244.950 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T21:47:24.950Z,1565387244.950 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T21:47:24.951Z,1565387244.951 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T21:47:25.338Z,1565387245.338 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,P
13A,000,00173,186,80,80,05,FF
2019-08-09T21:47:25.339Z,1565387245.339 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T21:47:25.339Z,1565387245.339 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T21:47:25.340Z,1565387245.340 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T21:47:25.717Z,1565387245.717 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T21:47:26.130Z,1565387246.130 [DUSBL_Hydroid](INFO): DUSBL response received:!U1,R,FAE,000,00039,184,80,80,0C,FF
2019-08-09T21:47:26.130Z,1565387246.130 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T21:47:26.881Z,1565387246.881 [CommandLine](IMPORTANT): got command stop
2019-08-09T21:47:26.881Z,1565387246.881 [CommandLine](IMPORTANT): Scheduling is paused
2019-08-09T21:47:26.881Z,1565387246.881 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-08-09T21:47:28.648Z,1565387248.648 [Micromodem](INFO): Nmea in: $SNTTA,,,,,214726.38*51

2019-08-09T21:47:28.715Z,1565387248.715 [MissionManager](INFO): MissionManager is completed.
2019-08-09T21:47:28.715Z,1565387248.715 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL] Stopped
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:A.Pitch] Stopped
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:B.SetSpeed] Stopped
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:C] Stopped
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:RequestRepeater] Stopped
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:RequestRepeater:A] Stopped
2019-08-09T21:47:28.715Z,1565387248.715 [DUSBL:RequestRepeater:B] Stopped
2019-08-09T21:47:28.716Z,1565387248.716 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-08-09T21:47:28.716Z,1565387248.716 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T21:47:28.838Z,1565387248.838 [MissionManager](IMPORTANT): Started mission Default
2019-08-09T21:47:28.838Z,1565387248.838 [Default] Running Loop=1
2019-08-09T21:47:28.838Z,1565387248.838 [Default](DEBUG): Aggregate::initialize Default
2019-08-09T21:47:28.838Z,1565387248.838 [Default:B.GoToSurface] Running Loop=1
2019-08-09T21:47:28.838Z,1565387248.838 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-09T21:47:28.838Z,1565387248.838 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-09T21:47:28.839Z,1565387248.839 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-09T21:47:28.839Z,1565387248.839 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-09T21:47:28.839Z,1565387248.839 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-09T21:47:28.840Z,1565387248.840 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-09T21:47:28.840Z,1565387248.840 [Default:A.Wait] Running Loop=1
2019-08-09T21:47:28.840Z,1565387248.840 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-09T21:47:42.121Z,1565387262.121 [Default:A.Wait](INFO): Done Waiting.
2019-08-09T21:47:42.121Z,1565387262.121 [Default:A.Wait] Stopped
2019-08-09T21:47:42.121Z,1565387262.121 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T21:47:42.530Z,1565387262.530 [Default:CheckIn] Running Loop=1
2019-08-09T21:47:42.530Z,1565387262.530 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-09T21:47:42.530Z,1565387262.530 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-09T21:47:42.943Z,1565387262.943 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-09T21:47:54.627Z,1565387274.627 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-09T21:47:55.444Z,1565387275.444 [NAL9602](DEBUG): Fix Requested
2019-08-09T21:47:55.833Z,1565387275.833 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214500.00,A,3648.16999,N,12147.28041,W,0.136,0.00,090819,,,A*7A
2019-08-09T21:47:55.836Z,1565387275.836 [NAL9602](INFO): GPS fix at 20190809T214500: (36.802833, -121.788007)
2019-08-09T21:47:55.871Z,1565387275.871 [Default:CheckIn:Read_GPS] Stopped
2019-08-09T21:47:55.871Z,1565387275.871 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-09T21:47:56.340Z,1565387276.340 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-09T21:48:03.828Z,1565387283.828 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190809T214202/Courier0004.lzma
2019-08-09T21:48:04.638Z,1565387284.638 [DataOverHttps](INFO): Moved sent file to Logs/20190809T214202/Courier0004.lzma.bak
2019-08-09T21:48:04.639Z,1565387284.639 [DataOverHttps](INFO): SBD MOMSN=11549061
2019-08-09T21:48:17.701Z,1565387297.701 [DataOverHttps](INFO): Sending 421 bytes from file Logs/20190809T214202/Express0005.lzma
2019-08-09T21:48:18.506Z,1565387298.506 [DataOverHttps](INFO): Moved sent file to Logs/20190809T214202/Express0005.lzma.bak
2019-08-09T21:48:18.506Z,1565387298.506 [DataOverHttps](INFO): SBD MOMSN=11549064
2019-08-09T21:48:19.820Z,1565387299.820 [Default:CheckIn:Read_Iridium] Stopped
2019-08-09T21:48:19.820Z,1565387299.820 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-09T21:48:19.833Z,1565387299.833 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T21:48:24.009Z,1565387304.009 [CommandLine](IMPORTANT): got command restart application
2019-08-09T21:48:25.013Z,1565387305.013 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:25.013Z,1565387305.013 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.212Z,1565387305.212 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-08-09T21:48:25.213Z,1565387305.213 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.213Z,1565387305.213 [CommandLine](INFO): Join timeout helper Thread ID is 5316
2019-08-09T21:48:25.228Z,1565387305.228 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-08-09T21:48:25.229Z,1565387305.229 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.229Z,1565387305.229 [NavChartDb](INFO): Join timeout helper Thread ID is 5317
2019-08-09T21:48:25.236Z,1565387305.236 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:25.241Z,1565387305.241 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.261Z,1565387305.261 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-08-09T21:48:25.261Z,1565387305.261 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.261Z,1565387305.261 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 5318
2019-08-09T21:48:25.657Z,1565387305.657 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:25.658Z,1565387305.658 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-08-09T21:48:25.661Z,1565387305.661 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.673Z,1565387305.673 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-08-09T21:48:25.673Z,1565387305.673 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.673Z,1565387305.673 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 5319
2019-08-09T21:48:25.773Z,1565387305.773 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:25.773Z,1565387305.773 [CTD_NeilBrown](INFO): Powering down
2019-08-09T21:48:25.785Z,1565387305.785 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.790Z,1565387305.790 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-08-09T21:48:25.790Z,1565387305.790 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:25.790Z,1565387305.790 [Radio_Surface](INFO): Join timeout helper Thread ID is 5320
2019-08-09T21:48:26.049Z,1565387306.049 [Radio_Surface](INFO): Powering down
2019-08-09T21:48:26.050Z,1565387306.050 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:26.050Z,1565387306.050 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.061Z,1565387306.061 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-08-09T21:48:26.062Z,1565387306.062 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.062Z,1565387306.062 [DataOverHttps](INFO): Join timeout helper Thread ID is 5321
2019-08-09T21:48:26.102Z,1565387306.102 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:26.106Z,1565387306.106 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.109Z,1565387306.109 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-08-09T21:48:26.109Z,1565387306.109 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.110Z,1565387306.110 [logger](INFO): Join timeout helper Thread ID is 5322
2019-08-09T21:48:26.117Z,1565387306.117 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:26.117Z,1565387306.117 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.129Z,1565387306.129 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-08-09T21:48:26.129Z,1565387306.129 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.129Z,1565387306.129 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-08-09T21:48:26.130Z,1565387306.130 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.130Z,1565387306.130 [controlThread](INFO): Join timeout helper Thread ID is 5323
2019-08-09T21:48:26.189Z,1565387306.189 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T21:48:26.189Z,1565387306.189 [controlThread](DEBUG): Uninitializing ControlThread
2019-08-09T21:48:26.189Z,1565387306.189 [AHRS_M2](INFO): Powering down
2019-08-09T21:48:26.261Z,1565387306.261 [DUSBL_Hydroid](INFO): Powering down
2019-08-09T21:48:26.333Z,1565387306.333 [Micromodem](INFO): Powering down
2019-08-09T21:48:26.429Z,1565387306.429 [NAL9602](INFO): Powering down
2019-08-09T21:48:26.501Z,1565387306.501 [RDI_Pathfinder](INFO): Powering down
2019-08-09T21:48:26.502Z,1565387306.502 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-08-09T21:48:26.503Z,1565387306.503 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-08-09T21:48:26.504Z,1565387306.504 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-08-09T21:48:26.504Z,1565387306.504 [MissionManager](INFO): Uninitializing Mission Default
2019-08-09T21:48:26.504Z,1565387306.504 [Default] Stopped
2019-08-09T21:48:26.505Z,1565387306.505 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-09T21:48:26.505Z,1565387306.505 [Default:B.GoToSurface] Stopped
2019-08-09T21:48:26.505Z,1565387306.505 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-09T21:48:26.505Z,1565387306.505 [Default:CheckIn] Stopped
2019-08-09T21:48:26.505Z,1565387306.505 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-09T21:48:26.505Z,1565387306.505 [Default:CheckIn:C.Wait] Stopped
2019-08-09T21:48:26.505Z,1565387306.505 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T21:48:26.507Z,1565387306.507 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-08-09T21:48:26.508Z,1565387306.508 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-08-09T21:48:26.508Z,1565387306.508 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-08-09T21:48:26.508Z,1565387306.508 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-08-09T21:48:26.509Z,1565387306.509 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-08-09T21:48:26.509Z,1565387306.509 [BuoyancyServo](INFO): Powering down
2019-08-09T21:48:26.520Z,1565387306.520 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-08-09T21:48:26.521Z,1565387306.521 [ElevatorServo](INFO): Powering down
2019-08-09T21:48:26.521Z,1565387306.521 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-08-09T21:48:26.521Z,1565387306.521 [MassServo](INFO): Powering down
2019-08-09T21:48:26.522Z,1565387306.522 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-09T21:48:26.522Z,1565387306.522 [RudderServo](INFO): Powering down
2019-08-09T21:48:26.523Z,1565387306.523 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-08-09T21:48:26.523Z,1565387306.523 [ThrusterServo](INFO): Powering down
2019-08-09T21:48:26.524Z,1565387306.524 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-08-09T21:48:26.524Z,1565387306.524 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-08-09T21:48:26.525Z,1565387306.525 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-08-09T21:48:26.525Z,1565387306.525 [CBIT](DEBUG): Powering off loads.
2019-08-09T21:48:26.536Z,1565387306.536 [CBIT](DEBUG): Disabling WDT.
2019-08-09T21:48:26.548Z,1565387306.548 [CBIT](DEBUG): Opening all GF detection circuits.
2019-08-09T21:48:26.549Z,1565387306.549 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.606Z,1565387306.606 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.616Z,1565387306.616 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.661Z,1565387306.661 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.664Z,1565387306.664 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.721Z,1565387306.721 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-09T21:48:26.786Z,1565387306.786 [logger ThreadHandler](INFO): Thread cancelled.