2019-08-09T20:18:41.740Z,1565381921.740 [Supervisor](DEBUG): Initializing supervisor.
2019-08-09T20:18:41.743Z,1565381921.743 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-09T20:18:41.743Z,1565381921.743 [SyncHandler](INFO): Protected caller Thread ID is 4579
2019-08-09T20:18:41.744Z,1565381921.744 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-09T20:18:41.745Z,1565381921.745 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-09T20:18:41.745Z,1565381921.745 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4580
2019-08-09T20:18:41.748Z,1565381921.748 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-09T20:18:41.760Z,1565381921.760 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-09T20:18:41.761Z,1565381921.761 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-09T20:18:41.761Z,1565381921.761 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4581
2019-08-09T20:18:41.762Z,1565381921.762 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-09T20:18:41.763Z,1565381921.763 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-09T20:18:41.763Z,1565381921.763 [logger ThreadHandler](INFO): Protected caller Thread ID is 4582
2019-08-09T20:18:41.765Z,1565381921.765 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-09T20:18:41.765Z,1565381921.765 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-09T20:18:41.767Z,1565381921.767 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-09T20:18:42.178Z,1565381922.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-09T20:18:42.178Z,1565381922.178 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-09T20:18:42.274Z,1565381922.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-09T20:18:42.274Z,1565381922.274 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-09T20:18:42.581Z,1565381922.581 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-09T20:18:42.581Z,1565381922.581 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-09T20:18:42.718Z,1565381922.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-09T20:18:42.718Z,1565381922.718 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-09T20:18:42.905Z,1565381922.905 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-09T20:18:42.905Z,1565381922.905 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-09T20:18:43.347Z,1565381923.347 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-09T20:18:43.348Z,1565381923.348 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-09T20:18:43.701Z,1565381923.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-09T20:18:43.702Z,1565381923.702 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-09T20:18:43.841Z,1565381923.841 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-09T20:18:43.842Z,1565381923.842 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-09T20:18:44.029Z,1565381924.029 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-09T20:18:44.030Z,1565381924.030 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-09T20:18:44.123Z,1565381924.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-09T20:18:44.123Z,1565381924.123 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-09T20:18:44.415Z,1565381924.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-09T20:18:44.416Z,1565381924.416 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-09T20:18:44.494Z,1565381924.494 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-09T20:18:44.594Z,1565381924.594 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-09T20:18:44.594Z,1565381924.594 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-09T20:18:45.169Z,1565381925.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-09T20:18:45.170Z,1565381925.170 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-09T20:18:45.557Z,1565381925.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-09T20:18:45.559Z,1565381925.559 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-08-09T20:18:45.560Z,1565381925.560 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-08-09T20:18:45.763Z,1565381925.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-08-09T20:18:45.861Z,1565381925.861 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-08-09T20:18:45.957Z,1565381925.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-08-09T20:18:46.181Z,1565381926.181 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-09T20:18:46.181Z,1565381926.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-08-09T20:18:46.263Z,1565381926.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-08-09T20:18:46.354Z,1565381926.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-08-09T20:18:46.447Z,1565381926.447 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-08-09T20:18:46.527Z,1565381926.527 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-08-09T20:18:46.633Z,1565381926.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-08-09T20:18:46.811Z,1565381926.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-08-09T20:18:46.940Z,1565381926.940 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-08-09T20:18:46.941Z,1565381926.941 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-09T20:18:46.950Z,1565381926.950 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-09T20:18:47.353Z,1565381927.353 [AHRS_M2] Loaded
2019-08-09T20:18:47.353Z,1565381927.353 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-08-09T20:18:47.428Z,1565381927.428 [DataOverHttps] Loaded
2019-08-09T20:18:47.428Z,1565381927.428 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-09T20:18:47.429Z,1565381927.429 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407664E0
2019-08-09T20:18:47.429Z,1565381927.429 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4661
2019-08-09T20:18:47.442Z,1565381927.442 [Depth_Keller] Loaded
2019-08-09T20:18:47.443Z,1565381927.443 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-09T20:18:47.447Z,1565381927.447 [DropWeight] Loaded
2019-08-09T20:18:47.447Z,1565381927.447 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-08-09T20:18:47.503Z,1565381927.503 [DUSBL_Hydroid] Loaded
2019-08-09T20:18:47.504Z,1565381927.504 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-08-09T20:18:47.551Z,1565381927.551 [Micromodem] Loaded
2019-08-09T20:18:47.551Z,1565381927.551 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-08-09T20:18:47.648Z,1565381927.648 [NAL9602] Loaded
2019-08-09T20:18:47.648Z,1565381927.648 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-09T20:18:47.664Z,1565381927.664 [Onboard] Loaded
2019-08-09T20:18:47.664Z,1565381927.664 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-09T20:18:47.670Z,1565381927.670 [PowerOnly] Loaded
2019-08-09T20:18:47.671Z,1565381927.671 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-08-09T20:18:47.677Z,1565381927.677 [Radio_Surface] Loaded
2019-08-09T20:18:47.677Z,1565381927.677 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-09T20:18:47.678Z,1565381927.678 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407964E0
2019-08-09T20:18:47.679Z,1565381927.679 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4662
2019-08-09T20:18:47.723Z,1565381927.723 [RDI_Pathfinder] Loaded
2019-08-09T20:18:47.723Z,1565381927.723 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-08-09T20:18:49.486Z,1565381929.486 [BPC1] Loaded
2019-08-09T20:18:49.486Z,1565381929.486 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-09T20:18:49.486Z,1565381929.486 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-09T20:18:49.487Z,1565381929.487 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-09T20:18:49.539Z,1565381929.539 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-09T20:18:49.540Z,1565381929.540 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-09T20:18:49.802Z,1565381929.802 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-09T20:18:49.802Z,1565381929.802 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-09T20:18:49.886Z,1565381929.886 [NavChart] Loaded
2019-08-09T20:18:49.887Z,1565381929.887 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-09T20:18:49.903Z,1565381929.903 [UniversalFixResidualReporter] Loaded
2019-08-09T20:18:49.904Z,1565381929.904 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-09T20:18:49.905Z,1565381929.905 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-09T20:18:49.905Z,1565381929.905 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-09T20:18:50.011Z,1565381930.011 [BuoyancyServo] Loaded
2019-08-09T20:18:50.012Z,1565381930.012 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-09T20:18:50.027Z,1565381930.027 [ElevatorServo] Loaded
2019-08-09T20:18:50.027Z,1565381930.027 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-09T20:18:50.042Z,1565381930.042 [MassServo] Loaded
2019-08-09T20:18:50.042Z,1565381930.042 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-09T20:18:50.057Z,1565381930.057 [RudderServo] Loaded
2019-08-09T20:18:50.057Z,1565381930.057 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-09T20:18:50.071Z,1565381930.071 [ThrusterServo] Loaded
2019-08-09T20:18:50.072Z,1565381930.072 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-09T20:18:50.072Z,1565381930.072 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-09T20:18:50.073Z,1565381930.073 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-09T20:18:50.319Z,1565381930.319 [CTD_NeilBrown] Loaded
2019-08-09T20:18:50.319Z,1565381930.319 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-08-09T20:18:50.320Z,1565381930.320 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E14E0
2019-08-09T20:18:50.321Z,1565381930.321 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4663
2019-08-09T20:18:50.350Z,1565381930.350 [ESPComponent] Loaded
2019-08-09T20:18:50.350Z,1565381930.350 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-08-09T20:18:50.394Z,1565381930.394 [WetLabsSeaOWL_UV_A] Loaded
2019-08-09T20:18:50.394Z,1565381930.394 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-08-09T20:18:50.395Z,1565381930.395 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409114E0
2019-08-09T20:18:50.396Z,1565381930.396 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 4664
2019-08-09T20:18:50.396Z,1565381930.396 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-09T20:18:50.397Z,1565381930.397 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-09T20:18:50.684Z,1565381930.684 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-09T20:18:50.685Z,1565381930.685 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-09T20:18:50.727Z,1565381930.727 [DepthRateCalculator] Loaded
2019-08-09T20:18:50.727Z,1565381930.727 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-09T20:18:50.732Z,1565381930.732 [PitchRateCalculator] Loaded
2019-08-09T20:18:50.733Z,1565381930.733 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-09T20:18:50.745Z,1565381930.745 [SpeedCalculator] Loaded
2019-08-09T20:18:50.745Z,1565381930.745 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-09T20:18:50.766Z,1565381930.766 [TempGradientCalculator] Loaded
2019-08-09T20:18:50.766Z,1565381930.766 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-09T20:18:50.772Z,1565381930.772 [YawRateCalculator] Loaded
2019-08-09T20:18:50.772Z,1565381930.772 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-09T20:18:50.812Z,1565381930.812 [ElevatorOffsetCalculator] Loaded
2019-08-09T20:18:50.812Z,1565381930.812 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-09T20:18:50.813Z,1565381930.813 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-09T20:18:50.813Z,1565381930.813 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-09T20:18:50.945Z,1565381930.945 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-09T20:18:50.967Z,1565381930.967 [SBIT] Loaded
2019-08-09T20:18:50.967Z,1565381930.967 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-09T20:18:50.968Z,1565381930.968 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-09T20:18:50.979Z,1565381930.979 [IBIT] Loaded
2019-08-09T20:18:50.979Z,1565381930.979 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-09T20:18:50.983Z,1565381930.983 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-09T20:18:51.118Z,1565381931.118 [CBIT] Loaded
2019-08-09T20:18:51.119Z,1565381931.119 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-09T20:18:51.119Z,1565381931.119 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-09T20:18:51.120Z,1565381931.120 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-09T20:18:51.199Z,1565381931.199 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-09T20:18:51.200Z,1565381931.200 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-09T20:18:51.298Z,1565381931.298 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-09T20:18:51.299Z,1565381931.299 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-09T20:18:51.365Z,1565381931.365 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-09T20:18:51.448Z,1565381931.448 [VerticalControl] Loaded
2019-08-09T20:18:51.448Z,1565381931.448 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-09T20:18:51.449Z,1565381931.449 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-09T20:18:51.505Z,1565381931.505 [HorizontalControl] Loaded
2019-08-09T20:18:51.506Z,1565381931.506 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-09T20:18:51.506Z,1565381931.506 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-09T20:18:51.508Z,1565381931.508 [SpeedControl] Loaded
2019-08-09T20:18:51.508Z,1565381931.508 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-09T20:18:51.509Z,1565381931.509 [LoopControl](DEBUG): Construct LoopControl.
2019-08-09T20:18:51.509Z,1565381931.509 [LoopControl] Loaded
2019-08-09T20:18:51.510Z,1565381931.510 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-09T20:18:51.510Z,1565381931.510 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-09T20:18:51.511Z,1565381931.511 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-09T20:18:51.542Z,1565381931.542 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-09T20:18:51.546Z,1565381931.546 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-09T20:18:51.547Z,1565381931.547 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-09T20:18:51.553Z,1565381931.553 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-09T20:18:51.554Z,1565381931.554 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AED4E0
2019-08-09T20:18:51.555Z,1565381931.555 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4665
2019-08-09T20:18:51.559Z,1565381931.559 [Supervisor](INFO): Main Thread ID is 4140
2019-08-09T20:18:51.559Z,1565381931.559 [Supervisor](DEBUG): Running supervisor.
2019-08-09T20:18:51.560Z,1565381931.560 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4666
2019-08-09T20:18:51.562Z,1565381931.562 [controlThread ThreadHandler](INFO): Handler Thread ID is 4667
2019-08-09T20:18:51.563Z,1565381931.563 [controlThread](DEBUG): Initializing ControlThread
2019-08-09T20:18:51.568Z,1565381931.568 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-09T20:18:51.568Z,1565381931.568 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-09T20:18:51.570Z,1565381931.570 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-09T20:18:51.570Z,1565381931.570 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-09T20:18:51.570Z,1565381931.570 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-09T20:18:51.571Z,1565381931.571 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-09T20:18:51.571Z,1565381931.571 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-09T20:18:51.571Z,1565381931.571 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-09T20:18:51.572Z,1565381931.572 [SBIT](INFO): Initialize SBIT Component.
2019-08-09T20:18:51.573Z,1565381931.573 [SBIT](IMPORTANT): git: 2019-07-16A-4-gbc3a532
2019-08-09T20:18:51.573Z,1565381931.573 [SBIT](INFO): git hash: bc3a532330c34a530d393d20f0a16563b6db3de2
2019-08-09T20:18:51.573Z,1565381931.573 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-09T20:18:51.574Z,1565381931.574 [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-09T20:18:51.575Z,1565381931.575 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-08-09T20:18:51.576Z,1565381931.576 [IBIT](INFO): Initialize IBIT Component.
2019-08-09T20:18:51.577Z,1565381931.577 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-09T20:18:51.578Z,1565381931.578 [logger ThreadHandler](INFO): Handler Thread ID is 4668
2019-08-09T20:18:51.588Z,1565381931.588 [CBIT](DEBUG): Initialized mux pins.
2019-08-09T20:18:51.589Z,1565381931.589 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-09T20:18:51.597Z,1565381931.597 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4669
2019-08-09T20:18:51.598Z,1565381931.598 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-09T20:18:51.609Z,1565381931.609 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4670
2019-08-09T20:18:51.613Z,1565381931.613 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-08-09T20:18:51.613Z,1565381931.613 [CBIT](DEBUG): Initializing heartbeat.
2019-08-09T20:18:51.621Z,1565381931.621 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4671
2019-08-09T20:18:51.622Z,1565381931.622 [CTD_NeilBrown](INFO): Powering down
2019-08-09T20:18:51.649Z,1565381931.649 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 4672
2019-08-09T20:18:51.650Z,1565381931.650 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-08-09T20:18:51.677Z,1565381931.677 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4673
2019-08-09T20:18:51.680Z,1565381931.680 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-09T20:18:51.680Z,1565381931.680 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-09T20:18:51.680Z,1565381931.680 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-09T20:18:51.680Z,1565381931.680 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-09T20:18:51.681Z,1565381931.681 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-09T20:18:51.681Z,1565381931.681 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-09T20:18:51.681Z,1565381931.681 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-09T20:18:51.681Z,1565381931.681 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-09T20:18:51.681Z,1565381931.681 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-09T20:18:51.682Z,1565381931.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-09T20:18:51.682Z,1565381931.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-09T20:18:51.682Z,1565381931.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-09T20:18:51.682Z,1565381931.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-09T20:18:51.682Z,1565381931.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-09T20:18:51.683Z,1565381931.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-09T20:18:51.683Z,1565381931.683 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-09T20:18:51.684Z,1565381931.684 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-09T20:18:51.685Z,1565381931.685 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-09T20:18:51.720Z,1565381931.720 [CBIT](DEBUG): Backplane powered.
2019-08-09T20:18:51.721Z,1565381931.721 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-09T20:18:51.723Z,1565381931.723 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-09T20:18:51.723Z,1565381931.723 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-09T20:18:51.724Z,1565381931.724 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-09T20:18:51.725Z,1565381931.725 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-09T20:18:51.735Z,1565381931.735 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-09T20:18:51.763Z,1565381931.763 [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-09T20:18:51.764Z,1565381931.764 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-09T20:18:51.837Z,1565381931.837 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-09T20:18:51.838Z,1565381931.838 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-09T20:18:51.839Z,1565381931.839 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-09T20:18:51.886Z,1565381931.886 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-09T20:18:51.889Z,1565381931.889 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-09T20:18:51.910Z,1565381931.910 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-09T20:18:51.914Z,1565381931.914 [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-09T20:18:51.918Z,1565381931.918 [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-09T20:18:51.935Z,1565381931.935 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-08-09T20:18:52.004Z,1565381932.004 [DUSBL_Hydroid](INFO): Powering up
2019-08-09T20:18:52.004Z,1565381932.004 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-08-09T20:18:52.013Z,1565381932.013 [Radio_Surface](INFO): Powering up
2019-08-09T20:18:52.098Z,1565381932.098 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-09T20:18:52.105Z,1565381932.105 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-09T20:18:52.106Z,1565381932.106 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-09T20:18:52.117Z,1565381932.117 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-09T20:18:52.118Z,1565381932.118 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-09T20:18:52.125Z,1565381932.125 [MassServo](DEBUG): Initializing MassServo.
2019-08-09T20:18:52.126Z,1565381932.126 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-09T20:18:52.133Z,1565381932.133 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-09T20:18:52.133Z,1565381932.134 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-09T20:18:52.141Z,1565381932.141 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-09T20:18:52.446Z,1565381932.446 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-08-09T20:18:52.446Z,1565381932.446 [DropWeight] Hardware Fault, FailCount= 1
2019-08-09T20:18:52.446Z,1565381932.446 [DropWeight](ERROR): Hardware Fault
2019-08-09T20:18:52.448Z,1565381932.448 [Micromodem](INFO): Powering up
2019-08-09T20:18:52.448Z,1565381932.448 [Micromodem](DEBUG): Initializing Micromodem.
2019-08-09T20:18:52.530Z,1565381932.530 [CommandLine](FAULT): Scheduling is paused
2019-08-09T20:18:52.530Z,1565381932.530 [CBIT](INFO): Critical error at 20190809T201852
2019-08-09T20:18:52.531Z,1565381932.531 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-08-09T20:18:52.541Z,1565381932.541 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-08-09T20:18:52.541Z,1565381932.542 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-08-09T20:18:53.073Z,1565381933.073 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-08-09T20:18:53.073Z,1565381933.073 [RudderServo](FAULT): Rudder failed to initialize
2019-08-09T20:18:53.073Z,1565381933.073 [RudderServo] Communications Fault, FailCount= 1
2019-08-09T20:18:53.073Z,1565381933.073 [RudderServo](ERROR): Communications Fault
2019-08-09T20:18:53.182Z,1565381933.182 [CBIT](INFO): Critical error at 20190809T201852
2019-08-09T20:18:53.184Z,1565381933.184 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-08-09T20:18:53.358Z,1565381933.358 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-09T20:18:53.358Z,1565381933.358 [RudderServo](INFO): Powering down
2019-08-09T20:18:54.037Z,1565381934.037 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-09T20:18:54.157Z,1565381934.157 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-09T20:18:54.162Z,1565381934.162 [CBIT](INFO): Clearing failed state for component RudderServo
2019-08-09T20:18:54.162Z,1565381934.162 [RudderServo] No Fault, FailCount= 1
2019-08-09T20:18:57.274Z,1565381937.274 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-08-09T20:18:57.680Z,1565381937.680 [Micromodem](INFO): Nmea in: $CATMG,2019-08-09T20:18:57.281141Z,RTC,RTC*5D

2019-08-09T20:18:57.680Z,1565381937.680 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-08-09T20:18:57.281141Z,RTC,RTC*5D

2019-08-09T20:18:58.158Z,1565381938.158 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-08-09T20:18:58.159Z,1565381938.159 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-08-09T20:18:58.575Z,1565381938.575 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-08-09T20:18:58.575Z,1565381938.575 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-08-09T20:18:58.979Z,1565381938.979 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-08-09T20:18:58.979Z,1565381938.979 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2019-08-09T20:18:59.380Z,1565381939.380 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2019-08-09T20:18:59.380Z,1565381939.380 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2019-08-09T20:18:59.787Z,1565381939.787 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2019-08-09T20:18:59.787Z,1565381939.787 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2019-08-09T20:19:00.179Z,1565381940.179 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2019-08-09T20:19:00.179Z,1565381940.179 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2019-08-09T20:19:00.591Z,1565381940.591 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2019-08-09T20:19:00.591Z,1565381940.591 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2019-08-09T20:19:00.975Z,1565381940.975 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2019-08-09T20:19:00.976Z,1565381940.976 [Micromodem](INFO): Nmea out: $CCCLK,2019,08,09,20,19,01*44

2019-08-09T20:19:01.387Z,1565381941.387 [Micromodem](INFO): Nmea in: $CACLK,2019,8,9,20,19,1*76

2019-08-09T20:19:01.389Z,1565381941.389 [Micromodem](INFO): Nmea in: $CATMS,0,2019-08-09T20:19:02Z*75

2019-08-09T20:19:01.390Z,1565381941.390 [Micromodem](INFO): Nmea in: $CATMG,2019-08-09T20:19:02.027427Z,USER_CMD,RTC*16

2019-08-09T20:19:05.461Z,1565381945.461 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-08-09T20:19:09.854Z,1565381949.854 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-08-09T20:19:17.931Z,1565381957.931 [NAL9602](INFO): Powering up NAL9602
2019-08-09T20:19:19.995Z,1565381959.995 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-09T20:19:20.003Z,1565381960.003 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-09T20:19:28.923Z,1565381968.923 [NAL9602](INFO): NAL9602 initialized
2019-08-09T20:19:29.748Z,1565381969.748 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:19:31.029Z,1565381971.029 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009282
CHAN A1 (24V): -0.027633
CHAN A2 (12V): -0.007209
CHAN A3 (5V): -0.002268
CHAN B0 (3.3V): -0.000092
CHAN B1 (3.15aV): -0.000275
CHAN B2 (3.15bV): -0.000160
CHAN B3 (GND): 0.002307
OPEN: 0.006542
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-09T20:19:47.604Z,1565381987.604 [NAL9602](INFO): SBD MO Status=0, MOMSN=8307, MT Status=0, MTMSN=0
2019-08-09T20:19:47.604Z,1565381987.604 [NAL9602](INFO): No messages in MT queue
2019-08-09T20:19:48.424Z,1565381988.424 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:19:51.656Z,1565381991.656 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:19:54.488Z,1565381994.488 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:19:57.316Z,1565381997.316 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:19:59.328Z,1565381999.328 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:01.352Z,1565382001.352 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:04.708Z,1565382004.708 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:07.532Z,1565382007.532 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:10.357Z,1565382010.357 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:12.784Z,1565382012.784 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:13.656Z,1565382013.656 [SBIT](IMPORTANT): SBIT PASSED
2019-08-09T20:20:13.682Z,1565382013.682 [CommandLine](IMPORTANT): got command configSet list
2019-08-09T20:20:13.682Z,1565382013.682 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-09T20:20:13.683Z,1565382013.683 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=10 count;

2019-08-09T20:20:13.683Z,1565382013.683 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2019-08-09T20:20:13.683Z,1565382013.683 [CommandLine](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2019-08-09T20:20:13.683Z,1565382013.683 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2019-08-09T20:20:13.683Z,1565382013.683 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 2.000000 meter;

2019-08-09T20:20:13.683Z,1565382013.683 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none;

2019-08-09T20:20:13.684Z,1565382013.684 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree;

2019-08-09T20:20:13.684Z,1565382013.684 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold=2 meter;

2019-08-09T20:20:13.684Z,1565382013.684 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-09T20:20:14.014Z,1565382014.014 [MissionManager](IMPORTANT): Started mission Startup
2019-08-09T20:20:14.014Z,1565382014.014 [Startup] Running Loop=1
2019-08-09T20:20:14.014Z,1565382014.014 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-09T20:20:14.014Z,1565382014.014 [Startup:A.GoToSurface] Running Loop=1
2019-08-09T20:20:14.014Z,1565382014.014 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-09T20:20:14.015Z,1565382014.015 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-09T20:20:14.015Z,1565382014.015 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-09T20:20:14.015Z,1565382014.015 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-09T20:20:14.016Z,1565382014.016 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-09T20:20:14.017Z,1565382014.017 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-09T20:20:14.018Z,1565382014.018 [Startup:StartupSatComms] Running Loop=1
2019-08-09T20:20:14.018Z,1565382014.018 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-09T20:20:14.018Z,1565382014.018 [Startup:StartupSatComms:A] Running Loop=1
2019-08-09T20:20:14.423Z,1565382014.423 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-09T20:20:15.611Z,1565382015.611 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:18.840Z,1565382018.840 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:21.668Z,1565382021.668 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:24.500Z,1565382024.500 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:27.736Z,1565382027.736 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:30.564Z,1565382030.564 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:33.388Z,1565382033.388 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:36.629Z,1565382036.629 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:39.448Z,1565382039.448 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:42.680Z,1565382042.680 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:45.504Z,1565382045.504 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:48.740Z,1565382048.740 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:51.568Z,1565382051.568 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:54.804Z,1565382054.804 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:20:57.628Z,1565382057.628 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:00.864Z,1565382060.864 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:03.688Z,1565382063.688 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:06.520Z,1565382066.520 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:09.349Z,1565382069.349 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:12.201Z,1565382072.201 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-08-09T20:21:12.201Z,1565382072.201 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.03,     ,        +0.02,   9.59,  0.00
2019-08-09T20:21:12.572Z,1565382072.572 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:14.247Z,1565382074.247 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-09T20:20:14.0Z
2019-08-09T20:21:14.247Z,1565382074.247 [Startup:StartupSatComms:A] Stopped
2019-08-09T20:21:14.248Z,1565382074.248 [Startup:StartupSatComms:B] Running Loop=1
2019-08-09T20:21:14.626Z,1565382074.626 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-09T20:21:15.476Z,1565382075.476 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:18.015Z,1565382078.015 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004944
2019-08-09T20:21:18.716Z,1565382078.716 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:21.536Z,1565382081.536 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:23.209Z,1565382083.209 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20190809T200931/Courier0007.lzma
2019-08-09T20:21:24.014Z,1565382084.014 [DataOverHttps](INFO): Moved sent file to Logs/20190809T200931/Courier0007.lzma.bak
2019-08-09T20:21:24.014Z,1565382084.014 [DataOverHttps](INFO): SBD MOMSN=11548274
2019-08-09T20:21:24.777Z,1565382084.777 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:27.600Z,1565382087.600 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:30.828Z,1565382090.828 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:33.656Z,1565382093.656 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:35.108Z,1565382095.108 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20190809T201841/Courier0000.lzma
2019-08-09T20:21:35.914Z,1565382095.914 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Courier0000.lzma.bak
2019-08-09T20:21:35.914Z,1565382095.914 [DataOverHttps](INFO): SBD MOMSN=11548276
2019-08-09T20:21:36.888Z,1565382096.888 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:39.716Z,1565382099.716 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:42.540Z,1565382102.540 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:45.373Z,1565382105.373 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:47.194Z,1565382107.194 [DataOverHttps](INFO): Sending 100 bytes from file Logs/20190809T200931/Express0008.lzma
2019-08-09T20:21:48.073Z,1565382108.073 [DataOverHttps](INFO): Moved sent file to Logs/20190809T200931/Express0008.lzma.bak
2019-08-09T20:21:48.073Z,1565382108.073 [DataOverHttps](INFO): SBD MOMSN=11548281
2019-08-09T20:21:48.628Z,1565382108.628 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:51.456Z,1565382111.456 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:51.884Z,1565382111.884 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-09T20:21:51.884Z,1565382111.884 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-09T20:21:51.894Z,1565382111.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-09T20:21:52.321Z,1565382112.321 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-09T20:21:52.321Z,1565382112.321 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-09T20:21:54.688Z,1565382114.688 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:57.525Z,1565382117.525 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:21:59.097Z,1565382119.097 [DataOverHttps](INFO): Sending 882 bytes from file Logs/20190809T201841/Express0001.lzma
2019-08-09T20:21:59.902Z,1565382119.902 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Express0001.lzma.bak
2019-08-09T20:21:59.902Z,1565382119.902 [DataOverHttps](INFO): SBD MOMSN=11548284
2019-08-09T20:22:00.757Z,1565382120.757 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:00.794Z,1565382120.794 [Startup:StartupSatComms:B] Stopped
2019-08-09T20:22:00.794Z,1565382120.794 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-09T20:22:00.794Z,1565382120.794 [Startup:StartupSatComms] Stopped
2019-08-09T20:22:00.794Z,1565382120.794 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-09T20:22:00.795Z,1565382120.795 [Startup](INFO): Completed Startup
2019-08-09T20:22:00.795Z,1565382120.795 [MissionManager](INFO): Startup is completed.
2019-08-09T20:22:00.795Z,1565382120.795 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-09T20:22:00.796Z,1565382120.796 [Startup] Stopped
2019-08-09T20:22:00.796Z,1565382120.796 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-09T20:22:00.796Z,1565382120.796 [Startup:A.GoToSurface] Stopped
2019-08-09T20:22:00.796Z,1565382120.796 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-09T20:22:01.228Z,1565382121.228 [MissionManager](IMPORTANT): Started mission Default
2019-08-09T20:22:01.228Z,1565382121.228 [Default] Running Loop=1
2019-08-09T20:22:01.228Z,1565382121.228 [Default](DEBUG): Aggregate::initialize Default
2019-08-09T20:22:01.228Z,1565382121.228 [Default:B.GoToSurface] Running Loop=1
2019-08-09T20:22:01.232Z,1565382121.232 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-09T20:22:01.233Z,1565382121.233 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-09T20:22:01.233Z,1565382121.233 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-09T20:22:01.233Z,1565382121.233 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-09T20:22:01.234Z,1565382121.234 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-09T20:22:01.234Z,1565382121.234 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-09T20:22:01.234Z,1565382121.234 [Default:A.Wait] Running Loop=1
2019-08-09T20:22:01.234Z,1565382121.234 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:22:03.587Z,1565382123.587 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:06.815Z,1565382126.815 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:09.641Z,1565382129.641 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:12.864Z,1565382132.864 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:14.498Z,1565382134.498 [Default:A.Wait](INFO): Done Waiting.
2019-08-09T20:22:14.498Z,1565382134.498 [Default:A.Wait] Stopped
2019-08-09T20:22:14.498Z,1565382134.498 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:22:14.902Z,1565382134.902 [Default:CheckIn] Running Loop=1
2019-08-09T20:22:14.902Z,1565382134.902 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-09T20:22:14.902Z,1565382134.902 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-09T20:22:15.315Z,1565382135.315 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-09T20:22:15.696Z,1565382135.696 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:18.536Z,1565382138.536 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:21.352Z,1565382141.352 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:24.584Z,1565382144.584 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:27.408Z,1565382147.408 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:30.649Z,1565382150.649 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:32.130Z,1565382152.130 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-08-09T20:22:32.131Z,1565382152.131 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-08-09T20:22:32.184Z,1565382152.184 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-08-09T20:22:32.193Z,1565382152.193 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-08-09T20:22:32.196Z,1565382152.196 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-08-09T20:22:32.199Z,1565382152.199 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-08-09T20:22:32.203Z,1565382152.203 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-08-09T20:22:32.204Z,1565382152.204 [DUSBL:A.Pitch](DEBUG): Construct.
2019-08-09T20:22:32.266Z,1565382152.266 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-08-09T20:22:32.318Z,1565382152.318 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-08-09T20:22:32.335Z,1565382152.335 [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-09T20:22:32.346Z,1565382152.346 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-08-09T20:22:32.673Z,1565382152.673 [Default] Stopped
2019-08-09T20:22:32.674Z,1565382152.674 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-09T20:22:32.674Z,1565382152.674 [Default:B.GoToSurface] Stopped
2019-08-09T20:22:32.674Z,1565382152.674 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-09T20:22:32.674Z,1565382152.674 [Default:CheckIn] Stopped
2019-08-09T20:22:32.674Z,1565382152.674 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-09T20:22:32.674Z,1565382152.674 [Default:CheckIn:Read_GPS] Stopped
2019-08-09T20:22:32.674Z,1565382152.674 [MissionManager](IMPORTANT): Started mission DUSBL
2019-08-09T20:22:32.674Z,1565382152.674 [DUSBL] Running Loop=1
2019-08-09T20:22:32.674Z,1565382152.674 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:A.Pitch] Running Loop=1
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:B.SetSpeed] Running Loop=1
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:C] Running Loop=1
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:RequestRepeater] Running Loop=1
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-08-09T20:22:32.675Z,1565382152.675 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T20:22:32.676Z,1565382152.676 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T20:22:32.676Z,1565382152.676 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-08-09T20:22:32.676Z,1565382152.676 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:22:32.676Z,1565382152.676 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T20:22:32.676Z,1565382152.676 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T20:22:32.677Z,1565382152.677 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-08-09T20:22:32.678Z,1565382152.678 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-08-09T20:22:32.678Z,1565382152.678 [DUSBL:B.SetSpeed] Running Loop=1
2019-08-09T20:22:32.678Z,1565382152.678 [DUSBL:A.Pitch] Running Loop=1
2019-08-09T20:22:33.481Z,1565382153.481 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:34.284Z,1565382154.284 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:34.284Z,1565382154.284 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:34.285Z,1565382154.285 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:34.286Z,1565382154.286 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:34.666Z,1565382154.666 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
O
2019-08-09T20:22:34.666Z,1565382154.666 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:22:34.666Z,1565382154.666 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:22:34.668Z,1565382154.668 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:22:35.483Z,1565382155.483 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F78,000,00038,187,80,80,0B,FF
2019-08-09T20:22:35.484Z,1565382155.484 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:22:35.890Z,1565382155.890 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:35.890Z,1565382155.890 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:35.890Z,1565382155.890 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:35.891Z,1565382155.891 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:35.896Z,1565382155.896 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202235.71*5C

2019-08-09T20:22:36.708Z,1565382156.708 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:39.532Z,1565382159.532 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:41.949Z,1565382161.949 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.057960
2019-08-09T20:22:41.949Z,1565382161.949 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:41.949Z,1565382161.949 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:41.949Z,1565382161.949 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:41.950Z,1565382161.950 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:42.346Z,1565382162.346 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F78,000,00038,187,80,80,0B,FF
2019-08-09T20:22:42.346Z,1565382162.346 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:22:42.346Z,1565382162.346 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:22:42.348Z,1565382162.348 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:22:42.777Z,1565382162.777 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:43.160Z,1565382163.160 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F7E,000,00037,186,80,80,0B,FF
2019-08-09T20:22:43.161Z,1565382163.161 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:22:43.557Z,1565382163.557 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:43.558Z,1565382163.558 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:43.558Z,1565382163.558 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:43.558Z,1565382163.558 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:43.560Z,1565382163.560 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202243.39*51

2019-08-09T20:22:45.601Z,1565382165.601 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:48.828Z,1565382168.828 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:49.629Z,1565382169.629 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.070252
2019-08-09T20:22:49.629Z,1565382169.629 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:49.629Z,1565382169.629 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:49.629Z,1565382169.629 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:49.630Z,1565382169.630 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:50.022Z,1565382170.022 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F7E,000,00037,186,80,80,0B,FF
2019-08-09T20:22:50.022Z,1565382170.022 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:22:50.022Z,1565382170.022 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:22:50.024Z,1565382170.024 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:22:50.830Z,1565382170.830 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F61,000,00038,186,80,80,0C,FF
2019-08-09T20:22:50.830Z,1565382170.830 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:22:51.238Z,1565382171.238 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:51.238Z,1565382171.238 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:51.238Z,1565382171.238 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:51.239Z,1565382171.239 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:51.244Z,1565382171.244 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202251.06*5E

2019-08-09T20:22:51.652Z,1565382171.652 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:54.888Z,1565382174.888 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:57.308Z,1565382177.308 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069969
2019-08-09T20:22:57.309Z,1565382177.309 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:57.309Z,1565382177.309 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:57.309Z,1565382177.309 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:57.310Z,1565382177.310 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:57.694Z,1565382177.694 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F61,000,00038,186,80,80,0C,FF
2019-08-09T20:22:57.694Z,1565382177.694 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:22:57.694Z,1565382177.694 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:22:57.696Z,1565382177.696 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T20:22:57.713Z,1565382177.713 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:22:58.105Z,1565382178.105 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T20:22:58.510Z,1565382178.510 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,006,000,0005E,183,80,80,0C,FF
2019-08-09T20:22:58.510Z,1565382178.510 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:22:58.914Z,1565382178.914 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:22:58.914Z,1565382178.914 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:22:58.914Z,1565382178.914 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:22:58.915Z,1565382178.915 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:22:58.920Z,1565382178.920 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202258.73*55

2019-08-09T20:23:00.544Z,1565382180.544 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:03.376Z,1565382183.376 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:04.976Z,1565382184.977 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.061965
2019-08-09T20:23:04.977Z,1565382184.977 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:04.977Z,1565382184.977 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:04.977Z,1565382184.977 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:04.978Z,1565382184.978 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:05.370Z,1565382185.370 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
006,000,0005E,183,80,80,0C,FF
2019-08-09T20:23:05.370Z,1565382185.370 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:05.370Z,1565382185.370 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:05.372Z,1565382185.372 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:06.193Z,1565382186.193 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F67,000,00038,187,80,80,0B,FF
2019-08-09T20:23:06.194Z,1565382186.194 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:23:06.590Z,1565382186.590 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:06.590Z,1565382186.590 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:06.590Z,1565382186.590 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:06.591Z,1565382186.591 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:06.596Z,1565382186.596 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202306.41*5E

2019-08-09T20:23:06.608Z,1565382186.608 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:09.433Z,1565382189.433 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:12.653Z,1565382192.653 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.061944
2019-08-09T20:23:12.653Z,1565382192.653 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:12.653Z,1565382192.653 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:12.653Z,1565382192.653 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:12.654Z,1565382192.654 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:12.672Z,1565382192.672 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:13.054Z,1565382193.054 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F67,000,00038,187,80,80,0B,FF
2019-08-09T20:23:13.054Z,1565382193.054 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:13.054Z,1565382193.054 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:13.056Z,1565382193.056 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:13.864Z,1565382193.864 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F7B,000,00038,186,80,80,0B,FF
2019-08-09T20:23:13.864Z,1565382193.864 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:23:14.262Z,1565382194.262 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:14.262Z,1565382194.262 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:14.262Z,1565382194.262 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:14.263Z,1565382194.263 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:14.268Z,1565382194.268 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202314.09*51

2019-08-09T20:23:15.492Z,1565382195.492 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:18.720Z,1565382198.720 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:20.333Z,1565382200.333 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069830
2019-08-09T20:23:20.333Z,1565382200.333 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:20.333Z,1565382200.333 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:20.333Z,1565382200.333 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:20.333Z,1565382200.333 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:20.726Z,1565382200.726 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F7B,000,00038,186,80,80,0B,FF
2019-08-09T20:23:20.726Z,1565382200.726 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:20.726Z,1565382200.726 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:20.727Z,1565382200.727 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:21.542Z,1565382201.542 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,01B,000,0005A,185,80,80,06,FF
2019-08-09T20:23:21.542Z,1565382201.542 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:23:21.556Z,1565382201.556 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:21.942Z,1565382201.942 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:21.942Z,1565382201.942 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:21.942Z,1565382201.942 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:21.943Z,1565382201.943 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:21.948Z,1565382201.948 [Micromodem](INFO): Nmea in: $SNTTA,0.122385,,,,202321.77*4F

2019-08-09T20:23:24.776Z,1565382204.776 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:27.613Z,1565382207.613 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:28.013Z,1565382208.013 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069979
2019-08-09T20:23:28.013Z,1565382208.013 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:28.013Z,1565382208.013 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:28.013Z,1565382208.013 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:28.014Z,1565382208.014 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:28.402Z,1565382208.402 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
01B,000,0005A,185,80,80,06,FF
2019-08-09T20:23:28.402Z,1565382208.402 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:28.402Z,1565382208.402 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:28.404Z,1565382208.404 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:29.206Z,1565382209.206 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F8B,000,00038,187,80,80,0B,FF
2019-08-09T20:23:29.206Z,1565382209.206 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:23:29.614Z,1565382209.614 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:29.614Z,1565382209.614 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:29.614Z,1565382209.614 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:29.615Z,1565382209.615 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:29.620Z,1565382209.620 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202329.44*56

2019-08-09T20:23:30.840Z,1565382210.840 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:33.676Z,1565382213.676 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:35.681Z,1565382215.681 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.065892
2019-08-09T20:23:35.681Z,1565382215.681 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:35.681Z,1565382215.681 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:35.681Z,1565382215.681 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:35.682Z,1565382215.682 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:36.078Z,1565382216.078 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F8B,000,00038,187,80,80,0B,FF
2019-08-09T20:23:36.078Z,1565382216.078 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:36.078Z,1565382216.078 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:36.080Z,1565382216.080 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:36.886Z,1565382216.886 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,00C,000,0005E,183,80,80,0D,FF
2019-08-09T20:23:36.886Z,1565382216.886 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:23:36.901Z,1565382216.901 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:37.290Z,1565382217.290 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:37.290Z,1565382217.290 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:37.290Z,1565382217.290 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:37.291Z,1565382217.291 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:37.305Z,1565382217.305 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202337.12*5A

2019-08-09T20:23:39.728Z,1565382219.728 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:42.956Z,1565382222.956 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:43.361Z,1565382223.361 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069328
2019-08-09T20:23:43.361Z,1565382223.361 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:43.361Z,1565382223.361 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:43.361Z,1565382223.361 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:43.362Z,1565382223.362 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:43.770Z,1565382223.770 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
00C,000,0005E,183,80,80,0D,FF
2019-08-09T20:23:43.770Z,1565382223.770 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:43.770Z,1565382223.770 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:43.772Z,1565382223.772 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:44.566Z,1565382224.566 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F83,000,00038,186,80,80,0C,FF
2019-08-09T20:23:44.566Z,1565382224.566 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:23:44.970Z,1565382224.970 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:44.970Z,1565382224.970 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:44.970Z,1565382224.970 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:44.971Z,1565382224.971 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:44.977Z,1565382224.977 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202344.81*54

2019-08-09T20:23:45.785Z,1565382225.785 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:48.612Z,1565382228.612 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:51.037Z,1565382231.037 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.065286
2019-08-09T20:23:51.037Z,1565382231.037 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:51.037Z,1565382231.037 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:51.037Z,1565382231.037 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:51.038Z,1565382231.038 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:51.426Z,1565382231.426 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F83,000,00038,186,80,80,0C,FF
2019-08-09T20:23:51.426Z,1565382231.426 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:51.426Z,1565382231.426 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:51.428Z,1565382231.428 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:51.868Z,1565382231.868 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:52.242Z,1565382232.242 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F85,000,00038,187,80,80,0B,FF
2019-08-09T20:23:52.242Z,1565382232.242 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:23:52.642Z,1565382232.642 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:52.642Z,1565382232.642 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:52.642Z,1565382232.642 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:52.642Z,1565382232.642 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:52.644Z,1565382232.644 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202352.47*59

2019-08-09T20:23:54.681Z,1565382234.681 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:57.508Z,1565382237.508 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:23:58.709Z,1565382238.709 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.066231
2019-08-09T20:23:58.709Z,1565382238.709 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:23:58.709Z,1565382238.709 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:23:58.709Z,1565382238.709 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:23:58.710Z,1565382238.710 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:23:59.110Z,1565382239.110 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F85,000,00038,187,80,80,0B,FF
2019-08-09T20:23:59.110Z,1565382239.110 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:23:59.110Z,1565382239.110 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:23:59.112Z,1565382239.112 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:23:59.914Z,1565382239.914 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F7E,000,00038,186,80,80,0D,FF
2019-08-09T20:23:59.914Z,1565382239.914 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:00.321Z,1565382240.321 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:00.322Z,1565382240.322 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:00.322Z,1565382240.322 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:00.323Z,1565382240.323 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:00.328Z,1565382240.328 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202400.15*5E

2019-08-09T20:24:00.744Z,1565382240.744 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:02.769Z,1565382242.769 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-08-09T20:24:02.769Z,1565382242.769 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-08-09T20:24:02.769Z,1565382242.769 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:24:02.769Z,1565382242.769 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater] Stopped
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater:A] Stopped
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater:B] Stopped
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater] Running Loop=2
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-08-09T20:24:02.770Z,1565382242.770 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:24:03.564Z,1565382243.564 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:03.586Z,1565382243.586 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,    +0,    -4,    +0,A
2019-08-09T20:24:06.393Z,1565382246.393 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069998
2019-08-09T20:24:06.393Z,1565382246.393 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:06.393Z,1565382246.393 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:06.393Z,1565382246.393 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:06.394Z,1565382246.394 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:06.778Z,1565382246.778 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F7E,000,00038,186,80,80,0D,FF
2019-08-09T20:24:06.778Z,1565382246.778 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:24:06.778Z,1565382246.778 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:24:06.780Z,1565382246.780 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T20:24:06.797Z,1565382246.797 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:07.201Z,1565382247.201 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T20:24:07.598Z,1565382247.598 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F90,000,00038,187,80,80,0C,FF
2019-08-09T20:24:07.598Z,1565382247.598 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:07.994Z,1565382247.994 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:07.994Z,1565382247.994 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:07.994Z,1565382247.994 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:07.995Z,1565382247.995 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:07.000Z,1565382248.000 [Micromodem](INFO): Nmea in: $SNTTA,0.159984,,,,202407.82*41

2019-08-09T20:24:09.628Z,1565382249.628 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:12.453Z,1565382252.453 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:14.065Z,1565382254.065 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069968
2019-08-09T20:24:14.065Z,1565382254.065 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:14.065Z,1565382254.065 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:14.065Z,1565382254.065 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:14.065Z,1565382254.065 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:14.458Z,1565382254.458 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F90,000,00038,187,80,80,0C,FF
2019-08-09T20:24:14.458Z,1565382254.458 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:24:14.458Z,1565382254.458 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:24:14.460Z,1565382254.460 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:24:15.266Z,1565382255.266 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,FA0,000,00039,186,80,80,0B,FF
2019-08-09T20:24:15.266Z,1565382255.266 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:15.669Z,1565382255.669 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:15.670Z,1565382255.670 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:15.670Z,1565382255.670 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:15.670Z,1565382255.670 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:15.672Z,1565382255.672 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202415.50*5B

2019-08-09T20:24:15.689Z,1565382255.689 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:18.508Z,1565382258.508 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:21.753Z,1565382261.753 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.082372
2019-08-09T20:24:21.753Z,1565382261.753 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:21.753Z,1565382261.753 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:21.753Z,1565382261.753 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:21.754Z,1565382261.754 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:21.772Z,1565382261.772 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:22.139Z,1565382262.139 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
FA0,000,00039,186,80,80,0B,FF
2019-08-09T20:24:22.139Z,1565382262.139 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:24:22.139Z,1565382262.139 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:24:22.141Z,1565382262.141 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T20:24:22.202Z,1565382262.202 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-08-09T20:24:22.202Z,1565382262.202 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,    4,    +0,A
2019-08-09T20:24:22.546Z,1565382262.546 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T20:24:22.946Z,1565382262.946 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,031,000,0005B,185,80,80,07,FF
2019-08-09T20:24:22.947Z,1565382262.947 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:23.350Z,1565382263.350 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:23.350Z,1565382263.350 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:23.350Z,1565382263.350 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:23.351Z,1565382263.351 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:23.356Z,1565382263.356 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202423.18*52

2019-08-09T20:24:24.580Z,1565382264.580 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:27.804Z,1565382267.804 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:29.421Z,1565382269.421 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069792
2019-08-09T20:24:29.421Z,1565382269.421 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:29.421Z,1565382269.421 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:29.421Z,1565382269.421 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:29.421Z,1565382269.421 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:29.814Z,1565382269.814 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
031,000,0005B,185,80,80,07,FF
2019-08-09T20:24:29.814Z,1565382269.814 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:24:29.814Z,1565382269.814 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:24:29.815Z,1565382269.815 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:24:30.622Z,1565382270.622 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,011,000,0005A,183,80,80,07,FF
2019-08-09T20:24:30.622Z,1565382270.622 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:30.636Z,1565382270.636 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:31.026Z,1565382271.026 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:31.026Z,1565382271.026 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:31.026Z,1565382271.026 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:31.026Z,1565382271.026 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:31.032Z,1565382271.032 [Micromodem](INFO): Nmea in: $SNTTA,0.159981,,,,202430.86*44

2019-08-09T20:24:33.460Z,1565382273.460 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:36.700Z,1565382276.700 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:37.093Z,1565382277.093 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.066243
2019-08-09T20:24:37.093Z,1565382277.093 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:37.093Z,1565382277.093 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:37.093Z,1565382277.093 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:37.094Z,1565382277.094 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:37.490Z,1565382277.490 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
011,000,0005A,183,80,80,07,FF
2019-08-09T20:24:37.490Z,1565382277.490 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:24:37.490Z,1565382277.490 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:24:37.492Z,1565382277.492 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:24:38.302Z,1565382278.302 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,FFE,000,0005E,183,80,80,0B,FF
2019-08-09T20:24:38.302Z,1565382278.302 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:38.706Z,1565382278.706 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:38.706Z,1565382278.706 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:38.706Z,1565382278.706 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:38.707Z,1565382278.707 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:38.712Z,1565382278.712 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202438.53*57

2019-08-09T20:24:39.524Z,1565382279.524 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:42.756Z,1565382282.756 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:44.777Z,1565382284.777 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069970
2019-08-09T20:24:44.777Z,1565382284.777 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:44.777Z,1565382284.777 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:44.777Z,1565382284.777 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:44.778Z,1565382284.778 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:45.185Z,1565382285.185 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
FFE,000,0005E,183,80,80,0B,FF
2019-08-09T20:24:45.185Z,1565382285.185 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:24:45.186Z,1565382285.186 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:24:45.190Z,1565382285.190 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:24:45.593Z,1565382285.593 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:45.974Z,1565382285.974 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,00E,000,0005B,183,80,80,08,FF
2019-08-09T20:24:45.975Z,1565382285.975 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:46.382Z,1565382286.382 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:46.382Z,1565382286.382 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:46.382Z,1565382286.382 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:46.383Z,1565382286.383 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:46.404Z,1565382286.404 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202446.23*59

2019-08-09T20:24:48.820Z,1565382288.820 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:51.644Z,1565382291.644 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:52.465Z,1565382292.465 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.081300
2019-08-09T20:24:52.465Z,1565382292.465 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:52.465Z,1565382292.465 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:52.465Z,1565382292.465 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:52.466Z,1565382292.466 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:52.855Z,1565382292.855 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
00E,000,0005B,183,80,80,08,FF
2019-08-09T20:24:52.855Z,1565382292.855 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:24:52.855Z,1565382292.855 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:24:52.857Z,1565382292.857 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T20:24:52.917Z,1565382292.917 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-08-09T20:24:52.917Z,1565382292.917 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-09T20:24:52.933Z,1565382292.933 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-09T20:24:53.253Z,1565382293.253 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T20:24:53.339Z,1565382293.339 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-09T20:24:53.339Z,1565382293.339 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-08-09T20:24:53.650Z,1565382293.650 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F79,000,00038,187,80,80,0C,FF
2019-08-09T20:24:53.650Z,1565382293.650 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:24:54.054Z,1565382294.054 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:24:54.054Z,1565382294.054 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:24:54.054Z,1565382294.054 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:24:54.055Z,1565382294.055 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:24:54.061Z,1565382294.061 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202453.90*55

2019-08-09T20:24:54.473Z,1565382294.473 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:24:57.705Z,1565382297.705 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:00.125Z,1565382300.125 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069608
2019-08-09T20:25:00.125Z,1565382300.125 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:00.125Z,1565382300.125 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:00.125Z,1565382300.125 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:00.126Z,1565382300.126 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:00.518Z,1565382300.518 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F79,000,00038,187,80,80,0C,FF
2019-08-09T20:25:00.518Z,1565382300.518 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:00.518Z,1565382300.518 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:00.520Z,1565382300.520 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T20:25:00.585Z,1565382300.585 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:00.929Z,1565382300.929 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T20:25:01.322Z,1565382301.322 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F98,000,00038,186,80,80,0D,FF
2019-08-09T20:25:01.322Z,1565382301.322 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:01.730Z,1565382301.730 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:01.730Z,1565382301.730 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:01.730Z,1565382301.730 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:01.731Z,1565382301.731 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:01.736Z,1565382301.736 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202501.56*59

2019-08-09T20:25:03.765Z,1565382303.765 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:06.600Z,1565382306.600 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:07.797Z,1565382307.797 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.065839
2019-08-09T20:25:07.797Z,1565382307.797 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:07.797Z,1565382307.797 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:07.797Z,1565382307.797 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:07.798Z,1565382307.798 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:08.202Z,1565382308.202 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F98,000,00038,186,80,80,0D,FF
2019-08-09T20:25:08.202Z,1565382308.202 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:08.202Z,1565382308.202 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:08.204Z,1565382308.204 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:25:08.998Z,1565382308.998 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,FEE,000,0005B,184,80,80,05,FF
2019-08-09T20:25:08.998Z,1565382308.998 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:09.410Z,1565382309.410 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:09.410Z,1565382309.410 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:09.410Z,1565382309.410 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:09.411Z,1565382309.411 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:09.417Z,1565382309.417 [Micromodem](INFO): Nmea in: $SNTTA,0.244513,,,,202509.24*4F

2019-08-09T20:25:09.820Z,1565382309.820 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:12.648Z,1565382312.648 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:15.485Z,1565382315.485 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.073338
2019-08-09T20:25:15.485Z,1565382315.485 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:15.485Z,1565382315.485 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:15.485Z,1565382315.485 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:15.486Z,1565382315.486 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:15.505Z,1565382315.505 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:15.878Z,1565382315.878 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
FEE,000,0005B,184,80,80,05,FF
2019-08-09T20:25:15.878Z,1565382315.878 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:15.878Z,1565382315.878 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:15.880Z,1565382315.880 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:25:16.674Z,1565382316.674 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,004,000,0005D,183,80,80,0B,FF
2019-08-09T20:25:16.674Z,1565382316.674 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:17.082Z,1565382317.082 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:17.082Z,1565382317.082 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:17.082Z,1565382317.082 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:17.083Z,1565382317.083 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:17.088Z,1565382317.088 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202516.91*54

2019-08-09T20:25:18.716Z,1565382318.716 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:21.544Z,1565382321.544 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:23.153Z,1565382323.153 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069550
2019-08-09T20:25:23.154Z,1565382323.154 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:23.154Z,1565382323.154 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:23.155Z,1565382323.155 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:23.156Z,1565382323.156 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:23.546Z,1565382323.546 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
004,000,0005D,183,80,80,0B,FF
2019-08-09T20:25:23.546Z,1565382323.546 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:23.546Z,1565382323.546 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:23.548Z,1565382323.548 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:25:24.358Z,1565382324.358 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F83,000,00038,186,80,80,0B,FF
2019-08-09T20:25:24.358Z,1565382324.358 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:24.758Z,1565382324.758 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:24.758Z,1565382324.758 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:24.758Z,1565382324.758 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:24.759Z,1565382324.759 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:24.764Z,1565382324.764 [Micromodem](INFO): Nmea in: $SNTTA,0.257477,,,,202524.59*4B

2019-08-09T20:25:24.776Z,1565382324.776 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:27.604Z,1565382327.604 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:30.833Z,1565382330.833 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.074027
2019-08-09T20:25:30.833Z,1565382330.833 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:30.833Z,1565382330.833 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:30.833Z,1565382330.833 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:30.834Z,1565382330.834 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:30.852Z,1565382330.852 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:31.226Z,1565382331.226 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F83,000,00038,186,80,80,0B,FF
2019-08-09T20:25:31.226Z,1565382331.226 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:31.226Z,1565382331.226 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:31.228Z,1565382331.228 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:25:32.030Z,1565382332.030 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,FFE,000,00061,183,80,80,06,FF
2019-08-09T20:25:32.030Z,1565382332.030 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:32.449Z,1565382332.449 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:32.450Z,1565382332.450 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:32.450Z,1565382332.450 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:32.451Z,1565382332.451 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:32.456Z,1565382332.456 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202532.27*5F

2019-08-09T20:25:33.294Z,1565382333.294 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-08-09T20:25:33.294Z,1565382333.294 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-08-09T20:25:33.294Z,1565382333.294 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:25:33.294Z,1565382333.294 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater] Stopped
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater:A] Stopped
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater:B] Stopped
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater] Running Loop=3
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-08-09T20:25:33.295Z,1565382333.295 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:25:33.668Z,1565382333.668 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:36.484Z,1565382336.484 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:38.505Z,1565382338.505 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.054096
2019-08-09T20:25:38.505Z,1565382338.505 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:38.505Z,1565382338.505 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:38.505Z,1565382338.505 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:38.505Z,1565382338.505 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:38.898Z,1565382338.898 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
FFE,000,00061,183,80,80,06,FF
2019-08-09T20:25:38.898Z,1565382338.898 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:38.898Z,1565382338.898 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:38.899Z,1565382338.899 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:25:39.714Z,1565382339.714 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F78,000,00038,186,80,80,0B,FF
2019-08-09T20:25:39.714Z,1565382339.714 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:39.729Z,1565382339.729 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:40.115Z,1565382340.115 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:40.115Z,1565382340.115 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:40.115Z,1565382340.115 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:40.115Z,1565382340.115 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:40.121Z,1565382340.121 [Micromodem](INFO): Nmea in: $SNTTA,0.136751,,,,202539.94*45

2019-08-09T20:25:42.544Z,1565382342.544 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:45.780Z,1565382345.780 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:46.197Z,1565382346.197 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.080877
2019-08-09T20:25:46.197Z,1565382346.197 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:46.197Z,1565382346.197 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:46.197Z,1565382346.197 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:46.198Z,1565382346.198 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:46.574Z,1565382346.574 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F78,000,00038,186,80,80,0B,FF
2019-08-09T20:25:46.574Z,1565382346.574 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:46.574Z,1565382346.574 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:46.576Z,1565382346.576 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:25:47.382Z,1565382347.382 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F8B,000,00039,187,80,80,0A,FF
2019-08-09T20:25:47.382Z,1565382347.382 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:47.790Z,1565382347.790 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:47.790Z,1565382347.790 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:47.790Z,1565382347.790 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:47.791Z,1565382347.791 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:47.796Z,1565382347.796 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202547.61*5F

2019-08-09T20:25:48.612Z,1565382348.612 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:51.844Z,1565382351.844 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:53.853Z,1565382353.853 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.062055
2019-08-09T20:25:53.853Z,1565382353.853 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:53.853Z,1565382353.853 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:53.853Z,1565382353.853 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:53.854Z,1565382353.854 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:54.250Z,1565382354.250 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F8B,000,00039,187,80,80,0A,FF
2019-08-09T20:25:54.250Z,1565382354.250 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:25:54.250Z,1565382354.250 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:25:54.252Z,1565382354.252 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:25:54.681Z,1565382354.681 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:25:55.058Z,1565382355.058 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F85,000,00038,187,80,80,0B,FF
2019-08-09T20:25:55.058Z,1565382355.058 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:25:55.466Z,1565382355.466 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:25:55.466Z,1565382355.466 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:25:55.466Z,1565382355.466 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:25:55.467Z,1565382355.467 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:25:55.472Z,1565382355.472 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202555.29*50

2019-08-09T20:25:57.500Z,1565382357.500 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:00.724Z,1565382360.724 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:01.533Z,1565382361.533 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.065968
2019-08-09T20:26:01.533Z,1565382361.533 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:01.533Z,1565382361.533 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:01.533Z,1565382361.533 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:01.534Z,1565382361.534 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:01.922Z,1565382361.922 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F85,000,00038,187,80,80,0B,FF
2019-08-09T20:26:01.922Z,1565382361.922 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:01.922Z,1565382361.922 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:01.924Z,1565382361.924 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:26:02.734Z,1565382362.734 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F76,000,00038,186,80,80,0C,FF
2019-08-09T20:26:02.734Z,1565382362.734 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:03.142Z,1565382363.142 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:03.142Z,1565382363.142 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:03.142Z,1565382363.142 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:03.143Z,1565382363.143 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:03.149Z,1565382363.149 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202602.96*55

2019-08-09T20:26:03.560Z,1565382363.560 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:06.788Z,1565382366.788 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:09.217Z,1565382369.217 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.073730
2019-08-09T20:26:09.217Z,1565382369.217 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:09.217Z,1565382369.217 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:09.217Z,1565382369.217 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:09.218Z,1565382369.218 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:09.602Z,1565382369.602 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F76,000,00038,186,80,80,0C,FF
2019-08-09T20:26:09.602Z,1565382369.602 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:09.602Z,1565382369.602 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:09.604Z,1565382369.604 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T20:26:09.621Z,1565382369.621 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:10.009Z,1565382370.009 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T20:26:10.414Z,1565382370.414 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F80,000,00038,187,80,80,0B,FF
2019-08-09T20:26:10.414Z,1565382370.414 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:10.814Z,1565382370.814 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:10.814Z,1565382370.814 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:10.814Z,1565382370.814 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:10.815Z,1565382370.815 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:10.821Z,1565382370.821 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202610.64*5B

2019-08-09T20:26:12.844Z,1565382372.844 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:15.685Z,1565382375.685 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:16.885Z,1565382376.885 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069506
2019-08-09T20:26:16.885Z,1565382376.885 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:16.885Z,1565382376.885 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:16.885Z,1565382376.885 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:16.885Z,1565382376.885 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:17.288Z,1565382377.288 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F80,000,00038,187,80,80,0B,FF
2019-08-09T20:26:17.288Z,1565382377.288 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:17.289Z,1565382377.289 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:17.290Z,1565382377.290 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:26:18.082Z,1565382378.082 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F78,000,00038,186,80,80,0B,FF
2019-08-09T20:26:18.082Z,1565382378.082 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:18.494Z,1565382378.494 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:18.494Z,1565382378.494 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:18.494Z,1565382378.494 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:18.495Z,1565382378.495 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:18.500Z,1565382378.500 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202618.33*51

2019-08-09T20:26:18.512Z,1565382378.512 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:21.732Z,1565382381.732 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:26:22.137Z,1565382382.137 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202328.00,A,3648.16893,N,12147.28314,W,1.263,345.67,090819,,,A*78
2019-08-09T20:26:22.140Z,1565382382.140 [NAL9602](INFO): GPS fix at 20190809T202328: (36.802816, -121.788052)
2019-08-09T20:26:24.569Z,1565382384.569 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.073832
2019-08-09T20:26:24.569Z,1565382384.569 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:24.569Z,1565382384.569 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:24.569Z,1565382384.569 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:24.570Z,1565382384.570 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:24.955Z,1565382384.955 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F78,000,00038,186,80,80,0B,FF
2019-08-09T20:26:24.955Z,1565382384.955 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:24.956Z,1565382384.956 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:24.957Z,1565382384.957 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:26:25.770Z,1565382385.770 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F85,000,00037,187,80,80,0B,FF
2019-08-09T20:26:25.770Z,1565382385.770 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:26.200Z,1565382386.200 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:26.200Z,1565382386.200 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:26.201Z,1565382386.201 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:26.201Z,1565382386.201 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:26.209Z,1565382386.209 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202626.00*5C

2019-08-09T20:26:26.395Z,1565382386.395 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-08-09T20:26:32.241Z,1565382392.241 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.039095
2019-08-09T20:26:32.241Z,1565382392.241 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:32.241Z,1565382392.241 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:32.241Z,1565382392.241 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:32.242Z,1565382392.242 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:32.638Z,1565382392.638 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F85,000,00037,187,80,80,0B,FF
2019-08-09T20:26:32.638Z,1565382392.638 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:32.638Z,1565382392.638 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:32.639Z,1565382392.639 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:26:33.441Z,1565382393.441 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F84,000,00038,186,80,80,0B,FF
2019-08-09T20:26:33.442Z,1565382393.442 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:33.850Z,1565382393.850 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:33.850Z,1565382393.850 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:33.850Z,1565382393.850 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:33.851Z,1565382393.851 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:33.856Z,1565382393.856 [Micromodem](INFO): Nmea in: $SNTTA,0.116018,,,,202633.68*47

2019-08-09T20:26:39.917Z,1565382399.917 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.065899
2019-08-09T20:26:39.917Z,1565382399.917 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:39.917Z,1565382399.917 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:39.917Z,1565382399.917 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:39.918Z,1565382399.918 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:40.307Z,1565382400.307 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F84,000,00038,186,80,80,0B,FF
2019-08-09T20:26:40.308Z,1565382400.308 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:40.308Z,1565382400.308 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:40.310Z,1565382400.310 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:26:41.122Z,1565382401.122 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F89,000,00037,186,80,80,0C,FF
2019-08-09T20:26:41.122Z,1565382401.122 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:41.522Z,1565382401.522 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:41.522Z,1565382401.522 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:41.522Z,1565382401.522 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:41.523Z,1565382401.523 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:41.528Z,1565382401.528 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202641.35*5B

2019-08-09T20:26:47.593Z,1565382407.593 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.069534
2019-08-09T20:26:47.593Z,1565382407.593 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:47.593Z,1565382407.593 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:47.593Z,1565382407.593 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:47.594Z,1565382407.594 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:47.989Z,1565382407.989 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F89,000,00037,186,80,80,0C,FF
2019-08-09T20:26:47.990Z,1565382407.990 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:47.990Z,1565382407.990 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:47.991Z,1565382407.991 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:26:48.798Z,1565382408.798 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,F8D,000,00038,187,80,80,0B,FF
2019-08-09T20:26:48.798Z,1565382408.798 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:49.204Z,1565382409.204 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:49.204Z,1565382409.204 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:49.208Z,1565382409.208 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:49.209Z,1565382409.209 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:49.217Z,1565382409.217 [Micromodem](INFO): Nmea in: $SNTTA,0.128899,,,,202649.03*4B

2019-08-09T20:26:51.262Z,1565382411.262 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-08-09T20:26:51.269Z,1565382411.269 [BPC1](INFO): Received data from all battery sticks.
2019-08-09T20:26:54.449Z,1565382414.449 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-09T20:26:55.273Z,1565382415.273 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.063406
2019-08-09T20:26:55.273Z,1565382415.273 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:55.273Z,1565382415.273 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:55.273Z,1565382415.273 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:55.274Z,1565382415.274 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:55.666Z,1565382415.666 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
F8D,000,00038,187,80,80,0B,FF
2019-08-09T20:26:55.666Z,1565382415.666 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:26:55.666Z,1565382415.666 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:26:55.667Z,1565382415.667 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:26:56.467Z,1565382416.467 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,027,000,0005A,184,80,80,08,FF
2019-08-09T20:26:56.468Z,1565382416.468 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:26:56.881Z,1565382416.881 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:26:56.881Z,1565382416.881 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:26:56.882Z,1565382416.882 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:26:56.882Z,1565382416.882 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:26:56.888Z,1565382416.888 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202656.71*5D

2019-08-09T20:27:02.949Z,1565382422.949 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.066247
2019-08-09T20:27:02.949Z,1565382422.949 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:27:02.949Z,1565382422.949 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:27:02.949Z,1565382422.949 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:27:02.950Z,1565382422.950 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:27:03.341Z,1565382423.341 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
027,000,0005A,184,80,80,08,FF
2019-08-09T20:27:03.342Z,1565382423.342 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:27:03.342Z,1565382423.342 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:27:03.343Z,1565382423.343 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:27:03.791Z,1565382423.791 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-08-09T20:27:03.792Z,1565382423.792 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-08-09T20:27:03.792Z,1565382423.792 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:27:03.794Z,1565382423.794 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-08-09T20:27:03.794Z,1565382423.794 [DUSBL:RequestRepeater] Stopped
2019-08-09T20:27:03.794Z,1565382423.794 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-08-09T20:27:03.794Z,1565382423.794 [DUSBL:RequestRepeater:A] Stopped
2019-08-09T20:27:03.794Z,1565382423.794 [DUSBL:RequestRepeater:B] Stopped
2019-08-09T20:27:03.794Z,1565382423.794 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-08-09T20:27:03.794Z,1565382423.794 [DUSBL:RequestRepeater] Running Loop=4
2019-08-09T20:27:03.796Z,1565382423.796 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-08-09T20:27:03.796Z,1565382423.796 [DUSBL:RequestRepeater:A] Running Loop=1
2019-08-09T20:27:03.796Z,1565382423.796 [DUSBL:RequestRepeater:B] Running Loop=1
2019-08-09T20:27:03.797Z,1565382423.797 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-08-09T20:27:03.797Z,1565382423.797 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:27:04.173Z,1565382424.173 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,FE7,000,0005A,184,80,80,08,FF
2019-08-09T20:27:04.174Z,1565382424.174 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:27:04.557Z,1565382424.557 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:27:04.557Z,1565382424.557 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:27:04.557Z,1565382424.557 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:27:04.558Z,1565382424.558 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:27:04.563Z,1565382424.563 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202704.38*56

2019-08-09T20:27:10.629Z,1565382430.629 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.070316
2019-08-09T20:27:10.629Z,1565382430.629 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:27:10.629Z,1565382430.629 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:27:10.629Z,1565382430.629 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:27:10.630Z,1565382430.630 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:27:11.014Z,1565382431.014 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
FE7,000,0005A,184,80,80,08,FF
2019-08-09T20:27:11.014Z,1565382431.014 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:27:11.014Z,1565382431.014 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:27:11.016Z,1565382431.016 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:27:11.822Z,1565382431.822 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,001,000,0005A,182,80,80,08,FF
2019-08-09T20:27:11.822Z,1565382431.822 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:27:12.227Z,1565382432.227 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:27:12.227Z,1565382432.227 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:27:12.227Z,1565382432.227 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:27:12.228Z,1565382432.228 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:27:12.233Z,1565382432.233 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202712.05*5F

2019-08-09T20:27:18.301Z,1565382438.301 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.072779
2019-08-09T20:27:18.301Z,1565382438.301 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:27:18.301Z,1565382438.301 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:27:18.301Z,1565382438.301 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:27:18.302Z,1565382438.302 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:27:18.696Z,1565382438.696 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
001,000,0005A,182,80,80,08,FF
2019-08-09T20:27:18.697Z,1565382438.697 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:27:18.697Z,1565382438.697 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:27:18.700Z,1565382438.700 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

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

2019-08-09T20:27:19.501Z,1565382439.501 [DUSBL_Hydroid](INFO): USBL response received:!U1,R,FC9,000,0005A,185,80,80,05,FF
2019-08-09T20:27:19.501Z,1565382439.501 [DUSBL_Hydroid](ERROR): Range is NaN. Not publishing.
2019-08-09T20:27:19.907Z,1565382439.907 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:27:19.907Z,1565382439.907 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:27:19.907Z,1565382439.907 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:27:19.908Z,1565382439.908 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:27:19.913Z,1565382439.913 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202719.74*52

2019-08-09T20:27:25.973Z,1565382445.973 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:6.064811
2019-08-09T20:27:25.973Z,1565382445.973 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-08-09T20:27:25.973Z,1565382445.973 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-08-09T20:27:25.973Z,1565382445.973 [DUSBL_Hydroid](INFO): Arming DUSBL. detectThresh: 10
2019-08-09T20:27:25.973Z,1565382445.973 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-08-09T20:27:26.018Z,1565382446.018 [CommandLine](IMPORTANT): got command stop
2019-08-09T20:27:26.018Z,1565382446.018 [CommandLine](IMPORTANT): Scheduling is paused
2019-08-09T20:27:26.018Z,1565382446.018 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-08-09T20:27:26.366Z,1565382446.366 [DUSBL_Hydroid](INFO): USBL response received:!U1,P
FC9,000,0005A,185,80,80,05,FF
2019-08-09T20:27:26.366Z,1565382446.366 [DUSBL_Hydroid](INFO): Command Ack
2019-08-09T20:27:26.366Z,1565382446.366 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-08-09T20:27:26.368Z,1565382446.368 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2019-08-09T20:27:26.509Z,1565382446.509 [MissionManager](INFO): MissionManager is completed.
2019-08-09T20:27:26.510Z,1565382446.510 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:A.Pitch] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:B.SetSpeed] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:C] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:RequestRepeater] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:RequestRepeater:A] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:RequestRepeater:B] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-08-09T20:27:26.510Z,1565382446.510 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:27:26.776Z,1565382446.776 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2019-08-09T20:27:26.824Z,1565382446.824 [MissionManager](IMPORTANT): Started mission Default
2019-08-09T20:27:26.824Z,1565382446.824 [Default] Running Loop=1
2019-08-09T20:27:26.824Z,1565382446.824 [Default](DEBUG): Aggregate::initialize Default
2019-08-09T20:27:26.824Z,1565382446.824 [Default:B.GoToSurface] Running Loop=1
2019-08-09T20:27:26.824Z,1565382446.824 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-09T20:27:26.829Z,1565382446.829 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-09T20:27:26.829Z,1565382446.829 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-09T20:27:26.829Z,1565382446.829 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-09T20:27:26.830Z,1565382446.830 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-09T20:27:26.830Z,1565382446.830 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-09T20:27:26.830Z,1565382446.830 [Default:A.Wait] Running Loop=1
2019-08-09T20:27:26.830Z,1565382446.830 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:27:27.582Z,1565382447.582 [Micromodem](INFO): Nmea in: $SNTTA,,,,,202727.41*59

2019-08-09T20:27:40.140Z,1565382460.140 [Default:A.Wait](INFO): Done Waiting.
2019-08-09T20:27:40.140Z,1565382460.140 [Default:A.Wait] Stopped
2019-08-09T20:27:40.140Z,1565382460.140 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:27:40.544Z,1565382460.544 [Default:CheckIn] Running Loop=1
2019-08-09T20:27:40.544Z,1565382460.544 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-09T20:27:40.544Z,1565382460.544 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-09T20:27:42.140Z,1565382462.140 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:28:05.181Z,1565382485.181 [NAL9602](INFO): SBD MO Status=0, MOMSN=8308, MT Status=0, MTMSN=0
2019-08-09T20:28:05.182Z,1565382485.182 [NAL9602](INFO): No messages in MT queue
2019-08-09T20:28:05.972Z,1565382485.972 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:28:08.796Z,1565382488.796 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:28:11.632Z,1565382491.632 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:28:12.024Z,1565382492.024 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202518.00,A,3648.16539,N,12147.28077,W,1.030,347.22,090819,,,A*71
2019-08-09T20:28:12.026Z,1565382492.026 [NAL9602](INFO): GPS fix at 20190809T202518: (36.802757, -121.788013)
2019-08-09T20:28:12.071Z,1565382492.071 [Default:CheckIn:Read_GPS] Stopped
2019-08-09T20:28:12.071Z,1565382492.071 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-09T20:28:12.479Z,1565382492.479 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-09T20:28:18.556Z,1565382498.556 [DataOverHttps](INFO): Sending 303 bytes from file Logs/20190809T201841/Courier0004.lzma
2019-08-09T20:28:19.362Z,1565382499.362 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Courier0004.lzma.bak
2019-08-09T20:28:19.362Z,1565382499.362 [DataOverHttps](INFO): SBD MOMSN=11548337
2019-08-09T20:28:37.732Z,1565382517.732 [DataOverHttps](INFO): Sending 341 bytes from file Logs/20190809T201841/Express0005.lzma
2019-08-09T20:28:38.538Z,1565382518.538 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Express0005.lzma.bak
2019-08-09T20:28:38.538Z,1565382518.538 [DataOverHttps](INFO): SBD MOMSN=11548372
2019-08-09T20:28:39.112Z,1565382519.112 [Default:CheckIn:Read_Iridium] Stopped
2019-08-09T20:28:39.112Z,1565382519.112 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-09T20:28:39.113Z,1565382519.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:28:44.746Z,1565382524.746 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-09T20:29:25.562Z,1565382565.562 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-08-09T20:29:25.563Z,1565382565.563 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19080913370572,35.0, -0.1,   0.0,10
2019-08-09T20:33:39.703Z,1565382819.703 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-09T20:33:39.703Z,1565382819.703 [Default:CheckIn:C.Wait] Stopped
2019-08-09T20:33:39.704Z,1565382819.704 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:33:39.704Z,1565382819.704 [Default:CheckIn:D] Running Loop=1
2019-08-09T20:33:40.094Z,1565382820.094 [Default:CheckIn:D] Stopped
2019-08-09T20:33:40.094Z,1565382820.094 [Default:CheckIn:E] Running Loop=1
2019-08-09T20:33:40.507Z,1565382820.507 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.221162 min 
2019-08-09T20:33:40.507Z,1565382820.507 [Default:CheckIn:E] Stopped
2019-08-09T20:33:40.507Z,1565382820.507 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-09T20:33:40.507Z,1565382820.507 [Default:CheckIn] Stopped
2019-08-09T20:33:40.507Z,1565382820.507 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-09T20:33:40.508Z,1565382820.508 [Default:CheckIn](INFO): Running loop #2
2019-08-09T20:33:40.508Z,1565382820.508 [Default:CheckIn] Running Loop=2
2019-08-09T20:33:40.508Z,1565382820.508 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-09T20:33:40.508Z,1565382820.508 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-09T20:33:42.100Z,1565382822.100 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:33:42.496Z,1565382822.496 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203048.00,A,3648.16579,N,12147.28019,W,0.233,341.93,090819,,,A*70
2019-08-09T20:33:42.507Z,1565382822.507 [NAL9602](INFO): GPS fix at 20190809T203048: (36.802763, -121.788003)
2019-08-09T20:33:42.544Z,1565382822.544 [Default:CheckIn:Read_GPS] Stopped
2019-08-09T20:33:42.544Z,1565382822.544 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-09T20:33:48.075Z,1565382828.075 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190809T201841/Courier0007.lzma
2019-08-09T20:33:48.818Z,1565382828.818 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Courier0007.lzma.bak
2019-08-09T20:33:48.818Z,1565382828.818 [DataOverHttps](INFO): SBD MOMSN=11548383
2019-08-09T20:33:52.649Z,1565382832.649 [CBIT](INFO): Clearing failed state for component DropWeight
2019-08-09T20:33:52.649Z,1565382832.649 [DropWeight] No Fault, FailCount= 1
2019-08-09T20:34:00.146Z,1565382840.146 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20190809T201841/Express0008.lzma
2019-08-09T20:34:00.954Z,1565382840.954 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Express0008.lzma.bak
2019-08-09T20:34:00.955Z,1565382840.955 [DataOverHttps](INFO): SBD MOMSN=11548386
2019-08-09T20:34:01.912Z,1565382841.912 [Default:CheckIn:Read_Iridium] Stopped
2019-08-09T20:34:01.912Z,1565382841.912 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-09T20:34:01.912Z,1565382841.912 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:34:19.704Z,1565382859.704 [NAL9602](INFO): SBD MO Status=2, MOMSN=8309, MT Status=2, MTMSN=0
2019-08-09T20:34:19.705Z,1565382859.705 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-09T20:34:28.990Z,1565382868.990 [NAL9602](INFO): SBD MO Status=0, MOMSN=8309, MT Status=0, MTMSN=0
2019-08-09T20:34:28.990Z,1565382868.990 [NAL9602](INFO): No messages in MT queue
2019-08-09T20:34:59.699Z,1565382899.699 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-09T20:36:05.192Z,1565382965.192 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-08-09T20:36:05.192Z,1565382965.192 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,    +0,    +0,    +,    +0,    +0,    +0,A
2019-08-09T20:39:02.539Z,1565383142.539 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-09T20:39:02.539Z,1565383142.539 [Default:CheckIn:C.Wait] Stopped
2019-08-09T20:39:02.539Z,1565383142.539 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:39:02.539Z,1565383142.539 [Default:CheckIn:D] Running Loop=1
2019-08-09T20:39:02.929Z,1565383142.929 [Default:CheckIn:D] Stopped
2019-08-09T20:39:02.929Z,1565383142.929 [Default:CheckIn:E] Running Loop=1
2019-08-09T20:39:03.364Z,1565383143.364 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.601752 min 
2019-08-09T20:39:03.364Z,1565383143.364 [Default:CheckIn:E] Stopped
2019-08-09T20:39:03.365Z,1565383143.365 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-09T20:39:03.365Z,1565383143.365 [Default:CheckIn] Stopped
2019-08-09T20:39:03.365Z,1565383143.365 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-09T20:39:03.365Z,1565383143.365 [Default:CheckIn](INFO): Running loop #3
2019-08-09T20:39:03.365Z,1565383143.365 [Default:CheckIn] Running Loop=3
2019-08-09T20:39:03.365Z,1565383143.365 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-09T20:39:03.365Z,1565383143.365 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-09T20:39:04.952Z,1565383144.952 [NAL9602](DEBUG): Fix Requested
2019-08-09T20:39:05.328Z,1565383145.328 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203611.00,A,3648.16652,N,12147.28336,W,0.117,305.92,090819,,,A*7A
2019-08-09T20:39:05.331Z,1565383145.331 [NAL9602](INFO): GPS fix at 20190809T203611: (36.802775, -121.788056)
2019-08-09T20:39:05.388Z,1565383145.388 [Default:CheckIn:Read_GPS] Stopped
2019-08-09T20:39:05.388Z,1565383145.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-09T20:39:13.480Z,1565383153.480 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190809T201841/Courier0010.lzma
2019-08-09T20:39:14.286Z,1565383154.286 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Courier0010.lzma.bak
2019-08-09T20:39:14.286Z,1565383154.286 [DataOverHttps](INFO): SBD MOMSN=11548441
2019-08-09T20:39:28.856Z,1565383168.856 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20190809T201841/Express0011.lzma
2019-08-09T20:39:29.662Z,1565383169.662 [DataOverHttps](INFO): Moved sent file to Logs/20190809T201841/Express0011.lzma.bak
2019-08-09T20:39:29.662Z,1565383169.662 [DataOverHttps](INFO): SBD MOMSN=11548444
2019-08-09T20:39:30.461Z,1565383170.461 [Default:CheckIn:Read_Iridium] Stopped
2019-08-09T20:39:30.461Z,1565383170.461 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-09T20:39:30.462Z,1565383170.462 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-09T20:39:32.618Z,1565383172.618 [CommandLine](IMPORTANT): got command restart application
2019-08-09T20:39:33.625Z,1565383173.625 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:33.625Z,1565383173.625 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:33.689Z,1565383173.689 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-08-09T20:39:33.689Z,1565383173.689 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:33.690Z,1565383173.690 [CommandLine](INFO): Join timeout helper Thread ID is 4734
2019-08-09T20:39:33.697Z,1565383173.697 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-08-09T20:39:33.697Z,1565383173.697 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:33.697Z,1565383173.697 [NavChartDb](INFO): Join timeout helper Thread ID is 4735
2019-08-09T20:39:33.773Z,1565383173.773 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:33.773Z,1565383173.773 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:33.789Z,1565383173.789 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-08-09T20:39:33.789Z,1565383173.789 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:33.789Z,1565383173.789 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 4736
2019-08-09T20:39:34.093Z,1565383174.093 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:34.093Z,1565383174.093 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-08-09T20:39:34.094Z,1565383174.094 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.101Z,1565383174.101 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-08-09T20:39:34.102Z,1565383174.102 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.103Z,1565383174.103 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4737
2019-08-09T20:39:34.113Z,1565383174.113 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:34.113Z,1565383174.113 [CTD_NeilBrown](INFO): Powering down
2019-08-09T20:39:34.125Z,1565383174.125 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.133Z,1565383174.133 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-08-09T20:39:34.133Z,1565383174.133 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.133Z,1565383174.133 [Radio_Surface](INFO): Join timeout helper Thread ID is 4738
2019-08-09T20:39:34.185Z,1565383174.185 [Radio_Surface](INFO): Powering down
2019-08-09T20:39:34.186Z,1565383174.186 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:34.186Z,1565383174.186 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.187Z,1565383174.187 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-08-09T20:39:34.187Z,1565383174.187 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.188Z,1565383174.188 [DataOverHttps](INFO): Join timeout helper Thread ID is 4739
2019-08-09T20:39:34.622Z,1565383174.622 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:34.626Z,1565383174.626 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.641Z,1565383174.641 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-08-09T20:39:34.641Z,1565383174.641 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.642Z,1565383174.642 [logger](INFO): Join timeout helper Thread ID is 4740
2019-08-09T20:39:34.657Z,1565383174.657 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:34.657Z,1565383174.657 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.661Z,1565383174.661 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-08-09T20:39:34.661Z,1565383174.661 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.661Z,1565383174.661 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-08-09T20:39:34.662Z,1565383174.662 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:34.662Z,1565383174.662 [controlThread](INFO): Join timeout helper Thread ID is 4741
2019-08-09T20:39:34.829Z,1565383174.829 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-09T20:39:34.829Z,1565383174.829 [controlThread](DEBUG): Uninitializing ControlThread
2019-08-09T20:39:34.829Z,1565383174.829 [AHRS_M2](INFO): Powering down
2019-08-09T20:39:34.901Z,1565383174.901 [DUSBL_Hydroid](INFO): Powering down
2019-08-09T20:39:34.973Z,1565383174.973 [Micromodem](INFO): Powering down
2019-08-09T20:39:35.069Z,1565383175.069 [NAL9602](INFO): Powering down
2019-08-09T20:39:35.141Z,1565383175.141 [RDI_Pathfinder](INFO): Powering down
2019-08-09T20:39:35.142Z,1565383175.142 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-08-09T20:39:35.143Z,1565383175.143 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-08-09T20:39:35.143Z,1565383175.143 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-08-09T20:39:35.144Z,1565383175.144 [MissionManager](INFO): Uninitializing Mission Default
2019-08-09T20:39:35.144Z,1565383175.144 [Default] Stopped
2019-08-09T20:39:35.144Z,1565383175.144 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-09T20:39:35.144Z,1565383175.144 [Default:B.GoToSurface] Stopped
2019-08-09T20:39:35.144Z,1565383175.144 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-09T20:39:35.144Z,1565383175.144 [Default:CheckIn] Stopped
2019-08-09T20:39:35.145Z,1565383175.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-09T20:39:35.145Z,1565383175.145 [Default:CheckIn:C.Wait] Stopped
2019-08-09T20:39:35.145Z,1565383175.145 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-09T20:39:35.147Z,1565383175.147 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-08-09T20:39:35.147Z,1565383175.147 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-08-09T20:39:35.148Z,1565383175.148 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-08-09T20:39:35.148Z,1565383175.148 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-08-09T20:39:35.148Z,1565383175.148 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-08-09T20:39:35.149Z,1565383175.149 [BuoyancyServo](INFO): Powering down
2019-08-09T20:39:35.161Z,1565383175.161 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-08-09T20:39:35.161Z,1565383175.161 [ElevatorServo](INFO): Powering down
2019-08-09T20:39:35.161Z,1565383175.161 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-08-09T20:39:35.162Z,1565383175.162 [MassServo](INFO): Powering down
2019-08-09T20:39:35.162Z,1565383175.162 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-09T20:39:35.162Z,1565383175.162 [RudderServo](INFO): Powering down
2019-08-09T20:39:35.163Z,1565383175.163 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-08-09T20:39:35.163Z,1565383175.163 [ThrusterServo](INFO): Powering down
2019-08-09T20:39:35.164Z,1565383175.164 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-08-09T20:39:35.165Z,1565383175.165 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-08-09T20:39:35.165Z,1565383175.165 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-08-09T20:39:35.165Z,1565383175.165 [CBIT](DEBUG): Powering off loads.
2019-08-09T20:39:35.176Z,1565383175.176 [CBIT](DEBUG): Disabling WDT.
2019-08-09T20:39:35.188Z,1565383175.188 [CBIT](DEBUG): Opening all GF detection circuits.
2019-08-09T20:39:35.189Z,1565383175.189 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:35.238Z,1565383175.238 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:35.247Z,1565383175.247 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:35.292Z,1565383175.292 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:35.295Z,1565383175.295 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:35.352Z,1565383175.352 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-09T20:39:35.410Z,1565383175.410 [logger ThreadHandler](INFO): Thread cancelled.