2019-05-06T17:47:44.294Z,1557164864.294 [Supervisor](DEBUG): Initializing supervisor.
2019-05-06T17:47:44.297Z,1557164864.297 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-06T17:47:44.298Z,1557164864.298 [SyncHandler](INFO): Protected caller Thread ID is 3067
2019-05-06T17:47:44.298Z,1557164864.298 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-06T17:47:44.299Z,1557164864.299 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-06T17:47:44.299Z,1557164864.299 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3068
2019-05-06T17:47:44.302Z,1557164864.302 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-06T17:47:44.314Z,1557164864.314 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-06T17:47:44.315Z,1557164864.315 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-06T17:47:44.316Z,1557164864.316 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3069
2019-05-06T17:47:44.316Z,1557164864.316 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-06T17:47:44.317Z,1557164864.317 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-06T17:47:44.318Z,1557164864.318 [logger ThreadHandler](INFO): Protected caller Thread ID is 3070
2019-05-06T17:47:44.320Z,1557164864.320 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-06T17:47:44.320Z,1557164864.320 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-06T17:47:44.322Z,1557164864.322 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-06T17:47:44.741Z,1557164864.741 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-06T17:47:44.741Z,1557164864.741 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-06T17:47:44.914Z,1557164864.914 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-06T17:47:44.915Z,1557164864.915 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-06T17:47:45.256Z,1557164865.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-06T17:47:45.257Z,1557164865.257 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-06T17:47:45.397Z,1557164865.397 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-06T17:47:45.398Z,1557164865.398 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-06T17:47:45.587Z,1557164865.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-06T17:47:45.588Z,1557164865.588 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-06T17:47:46.039Z,1557164866.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-06T17:47:46.040Z,1557164866.040 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-06T17:47:46.248Z,1557164866.248 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-06T17:47:46.249Z,1557164866.249 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-06T17:47:46.394Z,1557164866.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-06T17:47:46.394Z,1557164866.394 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-06T17:47:46.587Z,1557164866.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-06T17:47:46.587Z,1557164866.587 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-06T17:47:46.682Z,1557164866.682 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-06T17:47:46.682Z,1557164866.682 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-06T17:47:46.000Z,1557164867.000 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-06T17:47:47.000Z,1557164867.000 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-06T17:47:47.079Z,1557164867.079 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-06T17:47:47.181Z,1557164867.181 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-06T17:47:47.182Z,1557164867.182 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-06T17:47:47.753Z,1557164867.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-06T17:47:47.754Z,1557164867.754 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-06T17:47:48.144Z,1557164868.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-06T17:47:48.146Z,1557164868.146 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-06T17:47:48.147Z,1557164868.147 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-06T17:47:48.354Z,1557164868.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-06T17:47:48.453Z,1557164868.453 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-06T17:47:48.551Z,1557164868.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-06T17:47:48.775Z,1557164868.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-06T17:47:48.775Z,1557164868.775 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-06T17:47:48.859Z,1557164868.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-06T17:47:48.951Z,1557164868.951 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-06T17:47:49.047Z,1557164869.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-06T17:47:49.128Z,1557164869.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-06T17:47:49.235Z,1557164869.235 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-06T17:47:49.404Z,1557164869.404 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-06T17:47:49.535Z,1557164869.535 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-05-06T17:47:49.535Z,1557164869.535 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-06T17:47:49.548Z,1557164869.548 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-06T17:47:49.928Z,1557164869.928 [AHRS_M2] Loaded
2019-05-06T17:47:49.929Z,1557164869.929 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-06T17:47:50.001Z,1557164870.001 [DataOverHttps] Loaded
2019-05-06T17:47:50.002Z,1557164870.002 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-06T17:47:50.003Z,1557164870.003 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075A4E0
2019-05-06T17:47:50.003Z,1557164870.003 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3149
2019-05-06T17:47:50.016Z,1557164870.016 [Depth_Keller] Loaded
2019-05-06T17:47:50.016Z,1557164870.016 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-06T17:47:50.021Z,1557164870.021 [DropWeight] Loaded
2019-05-06T17:47:50.021Z,1557164870.021 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-06T17:47:50.077Z,1557164870.077 [DUSBL_Hydroid] Loaded
2019-05-06T17:47:50.077Z,1557164870.077 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-06T17:47:50.117Z,1557164870.117 [Micromodem] Loaded
2019-05-06T17:47:50.117Z,1557164870.117 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-06T17:47:50.214Z,1557164870.214 [NAL9602] Loaded
2019-05-06T17:47:50.214Z,1557164870.214 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-06T17:47:50.230Z,1557164870.230 [Onboard] Loaded
2019-05-06T17:47:50.230Z,1557164870.230 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-06T17:47:50.236Z,1557164870.236 [PowerOnly] Loaded
2019-05-06T17:47:50.236Z,1557164870.236 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-06T17:47:50.242Z,1557164870.242 [Radio_Surface] Loaded
2019-05-06T17:47:50.243Z,1557164870.243 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-06T17:47:50.244Z,1557164870.244 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078A4E0
2019-05-06T17:47:50.244Z,1557164870.244 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3150
2019-05-06T17:47:50.288Z,1557164870.288 [RDI_Pathfinder] Loaded
2019-05-06T17:47:50.288Z,1557164870.288 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-06T17:47:52.330Z,1557164872.330 [BPC1] Loaded
2019-05-06T17:47:52.330Z,1557164872.330 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-06T17:47:52.331Z,1557164872.331 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-06T17:47:52.331Z,1557164872.331 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-06T17:47:52.344Z,1557164872.344 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-06T17:47:52.345Z,1557164872.345 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-06T17:47:52.449Z,1557164872.449 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-06T17:47:52.449Z,1557164872.449 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-06T17:47:52.470Z,1557164872.470 [NavChart] Loaded
2019-05-06T17:47:52.470Z,1557164872.470 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-06T17:47:52.474Z,1557164872.474 [UniversalFixResidualReporter] Loaded
2019-05-06T17:47:52.474Z,1557164872.474 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-06T17:47:52.474Z,1557164872.474 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-06T17:47:52.475Z,1557164872.475 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-06T17:47:52.583Z,1557164872.583 [BuoyancyServo] Loaded
2019-05-06T17:47:52.583Z,1557164872.583 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-06T17:47:52.598Z,1557164872.598 [ElevatorServo] Loaded
2019-05-06T17:47:52.598Z,1557164872.598 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-06T17:47:52.613Z,1557164872.613 [MassServo] Loaded
2019-05-06T17:47:52.613Z,1557164872.613 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-06T17:47:52.628Z,1557164872.628 [RudderServo] Loaded
2019-05-06T17:47:52.628Z,1557164872.628 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-06T17:47:52.642Z,1557164872.642 [ThrusterServo] Loaded
2019-05-06T17:47:52.643Z,1557164872.643 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-06T17:47:52.643Z,1557164872.643 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-06T17:47:52.644Z,1557164872.644 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-06T17:47:52.889Z,1557164872.889 [CTD_NeilBrown] Loaded
2019-05-06T17:47:52.889Z,1557164872.889 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-06T17:47:52.890Z,1557164872.890 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408CC4E0
2019-05-06T17:47:52.891Z,1557164872.891 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 3151
2019-05-06T17:47:52.935Z,1557164872.935 [WetLabsSeaOWL_UV_A] Loaded
2019-05-06T17:47:52.935Z,1557164872.935 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-06T17:47:52.936Z,1557164872.936 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0
2019-05-06T17:47:52.936Z,1557164872.936 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 3152
2019-05-06T17:47:52.937Z,1557164872.937 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-06T17:47:52.937Z,1557164872.937 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-06T17:47:53.226Z,1557164873.226 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-06T17:47:53.227Z,1557164873.227 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-06T17:47:53.267Z,1557164873.267 [DepthRateCalculator] Loaded
2019-05-06T17:47:53.267Z,1557164873.267 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-06T17:47:53.272Z,1557164873.272 [PitchRateCalculator] Loaded
2019-05-06T17:47:53.273Z,1557164873.273 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-06T17:47:53.285Z,1557164873.285 [SpeedCalculator] Loaded
2019-05-06T17:47:53.285Z,1557164873.285 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-06T17:47:53.306Z,1557164873.306 [TempGradientCalculator] Loaded
2019-05-06T17:47:53.306Z,1557164873.306 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-06T17:47:53.312Z,1557164873.312 [YawRateCalculator] Loaded
2019-05-06T17:47:53.312Z,1557164873.312 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-06T17:47:53.352Z,1557164873.352 [ElevatorOffsetCalculator] Loaded
2019-05-06T17:47:53.352Z,1557164873.352 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-06T17:47:53.352Z,1557164873.352 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-06T17:47:53.353Z,1557164873.353 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-06T17:47:53.487Z,1557164873.487 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-06T17:47:53.509Z,1557164873.509 [SBIT] Loaded
2019-05-06T17:47:53.509Z,1557164873.509 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-06T17:47:53.510Z,1557164873.510 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-06T17:47:53.521Z,1557164873.521 [IBIT] Loaded
2019-05-06T17:47:53.522Z,1557164873.522 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-06T17:47:53.525Z,1557164873.525 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-06T17:47:53.660Z,1557164873.660 [CBIT] Loaded
2019-05-06T17:47:53.661Z,1557164873.661 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-06T17:47:53.661Z,1557164873.661 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-06T17:47:53.662Z,1557164873.662 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-06T17:47:53.732Z,1557164873.732 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-06T17:47:53.733Z,1557164873.733 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-06T17:47:53.830Z,1557164873.830 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-06T17:47:53.830Z,1557164873.830 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-06T17:47:53.896Z,1557164873.896 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-06T17:47:53.979Z,1557164873.979 [VerticalControl] Loaded
2019-05-06T17:47:53.980Z,1557164873.980 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-06T17:47:53.980Z,1557164873.980 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-06T17:47:54.038Z,1557164874.038 [HorizontalControl] Loaded
2019-05-06T17:47:54.038Z,1557164874.038 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-06T17:47:54.039Z,1557164874.039 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-06T17:47:54.040Z,1557164874.040 [SpeedControl] Loaded
2019-05-06T17:47:54.040Z,1557164874.040 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-06T17:47:54.041Z,1557164874.041 [LoopControl](DEBUG): Construct LoopControl.
2019-05-06T17:47:54.042Z,1557164874.042 [LoopControl] Loaded
2019-05-06T17:47:54.042Z,1557164874.042 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-06T17:47:54.042Z,1557164874.042 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-06T17:47:54.043Z,1557164874.043 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-06T17:47:54.069Z,1557164874.069 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-06T17:47:54.073Z,1557164874.073 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-06T17:47:54.074Z,1557164874.074 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-06T17:47:54.080Z,1557164874.080 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-06T17:47:54.081Z,1557164874.081 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD34E0
2019-05-06T17:47:54.082Z,1557164874.082 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3153
2019-05-06T17:47:54.086Z,1557164874.086 [Supervisor](INFO): Main Thread ID is 2877
2019-05-06T17:47:54.086Z,1557164874.086 [Supervisor](DEBUG): Running supervisor.
2019-05-06T17:47:54.087Z,1557164874.087 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3154
2019-05-06T17:47:54.090Z,1557164874.090 [controlThread ThreadHandler](INFO): Handler Thread ID is 3155
2019-05-06T17:47:54.090Z,1557164874.090 [controlThread](DEBUG): Initializing ControlThread
2019-05-06T17:47:54.096Z,1557164874.096 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-06T17:47:54.096Z,1557164874.096 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-06T17:47:54.097Z,1557164874.097 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-06T17:47:54.098Z,1557164874.098 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-06T17:47:54.098Z,1557164874.098 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-06T17:47:54.098Z,1557164874.098 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-06T17:47:54.099Z,1557164874.099 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-06T17:47:54.099Z,1557164874.099 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-06T17:47:54.100Z,1557164874.100 [SBIT](INFO): Initialize SBIT Component.
2019-05-06T17:47:54.100Z,1557164874.100 [SBIT](IMPORTANT): git: 2019-04-10-23-g672f59b
2019-05-06T17:47:54.100Z,1557164874.100 [SBIT](INFO): git hash: 672f59b3bb9ba34f4915fd4dcb9119316785292f
2019-05-06T17:47:54.101Z,1557164874.101 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-06T17:47:54.102Z,1557164874.102 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-06T17:47:54.103Z,1557164874.103 [SBIT](INFO): Beginning SBIT in 44.000000 seconds.
2019-05-06T17:47:54.104Z,1557164874.104 [IBIT](INFO): Initialize IBIT Component.
2019-05-06T17:47:54.104Z,1557164874.104 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-06T17:47:54.105Z,1557164874.105 [logger ThreadHandler](INFO): Handler Thread ID is 3156
2019-05-06T17:47:54.117Z,1557164874.117 [CBIT](DEBUG): Initialized mux pins.
2019-05-06T17:47:54.117Z,1557164874.117 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-06T17:47:54.125Z,1557164874.125 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3157
2019-05-06T17:47:54.126Z,1557164874.126 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-06T17:47:54.137Z,1557164874.137 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3158
2019-05-06T17:47:54.141Z,1557164874.141 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-06T17:47:54.141Z,1557164874.141 [CBIT](DEBUG): Initializing heartbeat.
2019-05-06T17:47:54.149Z,1557164874.149 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 3159
2019-05-06T17:47:54.150Z,1557164874.150 [CTD_NeilBrown](INFO): Powering down
2019-05-06T17:47:54.177Z,1557164874.177 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 3160
2019-05-06T17:47:54.178Z,1557164874.178 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-06T17:47:54.210Z,1557164874.210 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3161
2019-05-06T17:47:54.213Z,1557164874.213 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-06T17:47:54.213Z,1557164874.213 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-06T17:47:54.213Z,1557164874.213 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-06T17:47:54.213Z,1557164874.213 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-06T17:47:54.214Z,1557164874.214 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-06T17:47:54.214Z,1557164874.214 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-06T17:47:54.214Z,1557164874.214 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-06T17:47:54.214Z,1557164874.214 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-06T17:47:54.214Z,1557164874.214 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-06T17:47:54.215Z,1557164874.215 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-06T17:47:54.215Z,1557164874.215 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-06T17:47:54.215Z,1557164874.215 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-06T17:47:54.215Z,1557164874.215 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-06T17:47:54.215Z,1557164874.215 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-06T17:47:54.215Z,1557164874.215 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-06T17:47:54.216Z,1557164874.216 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-06T17:47:54.216Z,1557164874.216 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-06T17:47:54.216Z,1557164874.216 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-06T17:47:54.249Z,1557164874.249 [CBIT](DEBUG): Backplane powered.
2019-05-06T17:47:54.249Z,1557164874.249 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-06T17:47:54.251Z,1557164874.251 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-06T17:47:54.251Z,1557164874.251 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-06T17:47:54.252Z,1557164874.252 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-06T17:47:54.253Z,1557164874.253 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-06T17:47:54.262Z,1557164874.262 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-06T17:47:54.289Z,1557164874.289 [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-05-06T17:47:54.290Z,1557164874.290 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-06T17:47:54.361Z,1557164874.361 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-06T17:47:54.362Z,1557164874.362 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-06T17:47:54.364Z,1557164874.364 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-06T17:47:54.386Z,1557164874.386 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-06T17:47:54.413Z,1557164874.413 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-06T17:47:54.418Z,1557164874.418 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-06T17:47:54.438Z,1557164874.438 [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-05-06T17:47:54.442Z,1557164874.442 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-06T17:47:54.453Z,1557164874.453 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-06T17:47:54.497Z,1557164874.497 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-05-06T17:47:54.522Z,1557164874.522 [DUSBL_Hydroid](INFO): Powering up
2019-05-06T17:47:54.522Z,1557164874.522 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-06T17:47:54.541Z,1557164874.541 [Radio_Surface](INFO): Powering up
2019-05-06T17:47:54.602Z,1557164874.602 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-06T17:47:54.612Z,1557164874.612 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-06T17:47:54.617Z,1557164874.617 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-06T17:47:54.618Z,1557164874.618 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-06T17:47:54.625Z,1557164874.625 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-06T17:47:54.626Z,1557164874.626 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-06T17:47:54.645Z,1557164874.645 [MassServo](DEBUG): Initializing MassServo.
2019-05-06T17:47:54.646Z,1557164874.646 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-06T17:47:54.653Z,1557164874.653 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-06T17:47:54.654Z,1557164874.654 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-06T17:47:54.661Z,1557164874.661 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-06T17:47:54.867Z,1557164874.867 [Micromodem](INFO): Powering up
2019-05-06T17:47:54.867Z,1557164874.867 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-06T17:47:54.901Z,1557164874.901 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-06T17:47:55.585Z,1557164875.585 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-06T17:47:55.585Z,1557164875.585 [RudderServo](FAULT): Rudder failed to initialize
2019-05-06T17:47:55.585Z,1557164875.585 [RudderServo] Communications Fault, FailCount= 1
2019-05-06T17:47:55.585Z,1557164875.585 [RudderServo](ERROR): Communications Fault
2019-05-06T17:47:55.697Z,1557164875.697 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-06T17:47:55.870Z,1557164875.870 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-06T17:47:55.870Z,1557164875.870 [RudderServo](INFO): Powering down
2019-05-06T17:47:56.541Z,1557164876.541 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-06T17:47:56.662Z,1557164876.662 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-06T17:47:56.666Z,1557164876.666 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-06T17:47:56.666Z,1557164876.666 [RudderServo] No Fault, FailCount= 1
2019-05-06T17:48:07.928Z,1557164887.928 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-06T17:48:12.350Z,1557164892.350 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-06T17:48:20.427Z,1557164900.427 [NAL9602](INFO): Powering up NAL9602
2019-05-06T17:48:29.770Z,1557164909.770 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-06T17:48:29.770Z,1557164909.770 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-06T17:48:31.335Z,1557164911.335 [NAL9602](INFO): NAL9602 initialized
2019-05-06T17:48:32.157Z,1557164912.157 [NAL9602](DEBUG): Fix Requested
2019-05-06T17:48:32.955Z,1557164912.955 [Micromodem](ERROR): Response from modem unexpected: $CADQF,197,1*5F

2019-05-06T17:48:33.355Z,1557164913.355 [Micromodem](ERROR): Response from modem unexpected: $CAMSG,BAD_CRC,0*21

2019-05-06T17:48:33.774Z,1557164913.774 [Micromodem](ERROR): Response from modem unexpected: $CACST,6,1,20190506174830.831490,05,113,14,0091,0150,246,00,00,01,02,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,197,0.00,-999,9760,4000*56

2019-05-06T17:48:34.971Z,1557164914.971 [Micromodem](ERROR): Response from modem unexpected: $CADQF,194,1*5C

2019-05-06T17:48:35.375Z,1557164915.375 [Micromodem](ERROR): Response from modem unexpected: $CAMSG,BAD_CRC,0*21

2019-05-06T17:48:35.783Z,1557164915.783 [Micromodem](ERROR): Response from modem unexpected: $CACST,6,1,20190506174832.091764,05,332,13,0110,0150,246,00,00,02,02,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,194,0.00,-999,9760,4000*50

2019-05-06T17:48:38.651Z,1557164918.651 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-06T17:48:38.656Z,1557164918.656 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-06T17:48:49.690Z,1557164929.690 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.021740
CHAN A1 (24V): -0.026846
CHAN A2 (12V): -0.006833
CHAN A3 (5V): -0.001775
CHAN B0 (3.3V): 0.000102
CHAN B1 (3.15aV): 0.000195
CHAN B2 (3.15bV): -0.000007
CHAN B3 (GND): 0.001665
OPEN: 0.006650
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-06T17:49:06.325Z,1557164946.325 [NAL9602](INFO): SBD MO Status=2, MOMSN=3807, MT Status=2, MTMSN=0
2019-05-06T17:49:06.325Z,1557164946.325 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-06T17:49:23.787Z,1557164963.787 [NAL9602](INFO): SBD MO Status=2, MOMSN=3807, MT Status=2, MTMSN=0
2019-05-06T17:49:23.787Z,1557164963.787 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-06T17:49:31.894Z,1557164971.894 [SBIT](IMPORTANT): SBIT PASSED
2019-05-06T17:49:31.918Z,1557164971.918 [CommandLine](IMPORTANT): got command configSet list
2019-05-06T17:49:31.919Z,1557164971.919 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-06T17:49:31.919Z,1557164971.919 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=10 count;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-05-06T17:49:31.920Z,1557164971.920 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-05-06T17:49:31.921Z,1557164971.921 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-06T17:49:31.921Z,1557164971.921 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;

2019-05-06T17:49:31.921Z,1557164971.921 [CommandLine](IMPORTANT): VerticalControl.massDefault=6 millimeter;

2019-05-06T17:49:32.307Z,1557164972.307 [MissionManager](IMPORTANT): Started mission Startup
2019-05-06T17:49:32.307Z,1557164972.307 [Startup] Running Loop=1
2019-05-06T17:49:32.307Z,1557164972.307 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-06T17:49:32.307Z,1557164972.307 [Startup:A.GoToSurface] Running Loop=1
2019-05-06T17:49:32.307Z,1557164972.307 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-06T17:49:32.308Z,1557164972.308 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-06T17:49:32.308Z,1557164972.308 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-06T17:49:32.309Z,1557164972.309 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-06T17:49:32.309Z,1557164972.309 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-06T17:49:32.310Z,1557164972.310 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-06T17:49:32.311Z,1557164972.311 [Startup:StartupSatComms] Running Loop=1
2019-05-06T17:49:32.311Z,1557164972.311 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-06T17:49:32.311Z,1557164972.311 [Startup:StartupSatComms:A] Running Loop=1
2019-05-06T17:49:32.714Z,1557164972.714 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-06T17:49:54.098Z,1557164994.098 [NAL9602](INFO): SBD MO Status=2, MOMSN=3807, MT Status=2, MTMSN=0
2019-05-06T17:49:54.098Z,1557164994.098 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-06T17:50:09.452Z,1557165009.452 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2019-05-06T17:50:15.088Z,1557165015.088 [NAL9602](INFO): SBD MO Status=2, MOMSN=3807, MT Status=2, MTMSN=0
2019-05-06T17:50:15.089Z,1557165015.089 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-06T17:50:20.283Z,1557165020.283 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004860
2019-05-06T17:50:32.490Z,1557165032.490 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-06T17:49:32.3Z
2019-05-06T17:50:32.490Z,1557165032.490 [Startup:StartupSatComms:A] Stopped
2019-05-06T17:50:32.491Z,1557165032.491 [Startup:StartupSatComms:B] Running Loop=1
2019-05-06T17:50:32.910Z,1557165032.910 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-06T17:50:38.304Z,1557165038.304 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190506T164729/Courier0022.lzma
2019-05-06T17:50:39.111Z,1557165039.111 [DataOverHttps](INFO): Moved sent file to Logs/20190506T164729/Courier0022.lzma.bak
2019-05-06T17:50:39.111Z,1557165039.111 [DataOverHttps](INFO): SBD MOMSN=10942482
2019-05-06T17:50:50.784Z,1557165050.784 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20190506T164729/Express0023.lzma
2019-05-06T17:50:51.591Z,1557165051.591 [DataOverHttps](INFO): Moved sent file to Logs/20190506T164729/Express0023.lzma.bak
2019-05-06T17:50:51.591Z,1557165051.591 [DataOverHttps](INFO): SBD MOMSN=10942484
2019-05-06T17:50:54.314Z,1557165054.314 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-06T17:50:54.314Z,1557165054.314 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-06T17:50:54.329Z,1557165054.329 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-06T17:50:54.765Z,1557165054.765 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-06T17:50:54.765Z,1557165054.765 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-06T17:51:05.592Z,1557165065.592 [NAL9602](INFO): SBD MO Status=2, MOMSN=3807, MT Status=2, MTMSN=0
2019-05-06T17:51:05.592Z,1557165065.592 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-06T17:51:06.679Z,1557165066.679 [DataOverHttps](INFO): Sending 1307 bytes from file Logs/20190506T174744/Express0001.lzma
2019-05-06T17:51:07.483Z,1557165067.483 [DataOverHttps](INFO): Moved sent file to Logs/20190506T174744/Express0001.lzma.bak
2019-05-06T17:51:07.483Z,1557165067.483 [DataOverHttps](INFO): SBD MOMSN=10942487
2019-05-06T17:51:08.458Z,1557165068.458 [Startup:StartupSatComms:B] Stopped
2019-05-06T17:51:08.458Z,1557165068.458 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-06T17:51:08.458Z,1557165068.458 [Startup:StartupSatComms] Stopped
2019-05-06T17:51:08.458Z,1557165068.458 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-06T17:51:08.459Z,1557165068.459 [Startup](INFO): Completed Startup
2019-05-06T17:51:08.459Z,1557165068.459 [MissionManager](INFO): Startup is completed.
2019-05-06T17:51:08.459Z,1557165068.459 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-06T17:51:08.459Z,1557165068.459 [Startup] Stopped
2019-05-06T17:51:08.460Z,1557165068.460 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-06T17:51:08.460Z,1557165068.460 [Startup:A.GoToSurface] Stopped
2019-05-06T17:51:08.460Z,1557165068.460 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-06T17:51:08.910Z,1557165068.910 [MissionManager](IMPORTANT): Started mission Default
2019-05-06T17:51:08.910Z,1557165068.910 [Default] Running Loop=1
2019-05-06T17:51:08.910Z,1557165068.910 [Default](DEBUG): Aggregate::initialize Default
2019-05-06T17:51:08.910Z,1557165068.910 [Default:B.GoToSurface] Running Loop=1
2019-05-06T17:51:08.911Z,1557165068.911 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-06T17:51:08.911Z,1557165068.911 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-06T17:51:08.911Z,1557165068.911 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-06T17:51:08.911Z,1557165068.911 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-06T17:51:08.912Z,1557165068.912 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-06T17:51:08.912Z,1557165068.912 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-06T17:51:08.912Z,1557165068.912 [Default:A.Wait] Running Loop=1
2019-05-06T17:51:08.912Z,1557165068.912 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:51:15.762Z,1557165075.762 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-06T17:51:15.762Z,1557165075.762 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-06T17:51:22.194Z,1557165082.194 [Default:A.Wait](INFO): Done Waiting.
2019-05-06T17:51:22.194Z,1557165082.194 [Default:A.Wait] Stopped
2019-05-06T17:51:22.195Z,1557165082.195 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:51:22.595Z,1557165082.595 [Default:CheckIn] Running Loop=1
2019-05-06T17:51:22.595Z,1557165082.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-06T17:51:22.595Z,1557165082.595 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-06T17:51:23.078Z,1557165083.078 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-06T17:51:23.373Z,1557165083.373 [NAL9602](INFO): SBD MO Status=2, MOMSN=3807, MT Status=2, MTMSN=0
2019-05-06T17:51:23.373Z,1557165083.373 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-06T17:52:35.255Z,1557165155.255 [CommandLine](IMPORTANT): got command show variable range
2019-05-06T17:52:35.257Z,1557165155.257 [CommandLine](IMPORTANT): acoustic_contact_range (unknown)
2019-05-06T17:52:35.401Z,1557165155.401 [CommandLine](IMPORTANT): BR_Ping1D.minrange (meter)
2019-05-06T17:52:35.402Z,1557165155.402 [CommandLine](IMPORTANT): BR_Ping1D.maxrange (meter)
2019-05-06T17:52:35.438Z,1557165155.438 [CommandLine](IMPORTANT): DUSBL_Hydroid.acoustic_contact_range (meter)
2019-05-06T17:52:35.439Z,1557165155.439 [CommandLine](IMPORTANT): Micromodem.range_request (count)
2019-05-06T17:52:35.439Z,1557165155.439 [CommandLine](IMPORTANT): Micromodem.range (meter)
2019-05-06T17:52:35.442Z,1557165155.442 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam1Range (meter)
2019-05-06T17:52:35.443Z,1557165155.443 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam2Range (meter)
2019-05-06T17:52:35.443Z,1557165155.443 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam3Range (meter)
2019-05-06T17:52:35.444Z,1557165155.444 [CommandLine](IMPORTANT): RDI_Pathfinder.Beam4Range (meter)
2019-05-06T17:52:43.823Z,1557165163.823 [CommandLine](IMPORTANT): got command report touch acoustic_contact_range
2019-05-06T17:52:48.243Z,1557165168.243 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-05-06T17:52:48.243Z,1557165168.243 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-05-06T17:52:48.293Z,1557165168.293 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-05-06T17:52:48.301Z,1557165168.301 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-05-06T17:52:48.309Z,1557165168.309 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-05-06T17:52:48.312Z,1557165168.312 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-05-06T17:52:48.320Z,1557165168.320 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-05-06T17:52:48.325Z,1557165168.325 [DUSBL:A.Pitch](DEBUG): Construct.
2019-05-06T17:52:48.332Z,1557165168.332 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-05-06T17:52:48.365Z,1557165168.365 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-05-06T17:52:48.373Z,1557165168.373 [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>10</Value></Setting>
          </Guidance:Wait>
      </Aggregate>    
</Mission>


2019-05-06T17:52:48.375Z,1557165168.375 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-05-06T17:52:48.642Z,1557165168.642 [Default] Stopped
2019-05-06T17:52:48.642Z,1557165168.642 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-06T17:52:48.642Z,1557165168.642 [Default:B.GoToSurface] Stopped
2019-05-06T17:52:48.642Z,1557165168.642 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-06T17:52:48.642Z,1557165168.642 [Default:CheckIn] Stopped
2019-05-06T17:52:48.642Z,1557165168.642 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-06T17:52:48.642Z,1557165168.642 [Default:CheckIn:Read_GPS] Stopped
2019-05-06T17:52:48.642Z,1557165168.642 [MissionManager](IMPORTANT): Started mission DUSBL
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL] Running Loop=1
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL:A.Pitch] Running Loop=1
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL:C] Running Loop=1
2019-05-06T17:52:48.643Z,1557165168.643 [DUSBL:RequestRepeater] Running Loop=1
2019-05-06T17:52:48.644Z,1557165168.644 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:52:48.644Z,1557165168.644 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:52:48.644Z,1557165168.644 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:52:48.644Z,1557165168.644 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:52:48.644Z,1557165168.644 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:52:48.644Z,1557165168.644 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:52:48.644Z,1557165168.644 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:52:48.646Z,1557165168.646 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_range
2019-05-06T17:52:48.646Z,1557165168.646 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense acoustic_contact_direction_vehicle_frame
2019-05-06T17:52:48.646Z,1557165168.646 [DUSBL:B.SetSpeed] Running Loop=1
2019-05-06T17:52:48.646Z,1557165168.646 [DUSBL:A.Pitch] Running Loop=1
2019-05-06T17:52:50.226Z,1557165170.226 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:52:50.226Z,1557165170.226 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:52:50.227Z,1557165170.227 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:52:50.229Z,1557165170.229 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:50.630Z,1557165170.630 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:50.630Z,1557165170.630 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:52:50.631Z,1557165170.631 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:52:50.646Z,1557165170.646 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:52:51.060Z,1557165171.060 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:51.442Z,1557165171.442 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:51.847Z,1557165171.847 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:52.262Z,1557165172.262 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:52.650Z,1557165172.650 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:53.062Z,1557165173.062 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:53.476Z,1557165173.476 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:53.866Z,1557165173.866 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:54.273Z,1557165174.273 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:54.682Z,1557165174.682 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:55.078Z,1557165175.078 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:55.497Z,1557165175.497 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.269570
2019-05-06T17:52:55.497Z,1557165175.497 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:52:55.497Z,1557165175.497 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:52:55.498Z,1557165175.498 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:52:55.499Z,1557165175.499 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:55.886Z,1557165175.886 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:55.887Z,1557165175.887 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:52:55.887Z,1557165175.887 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:52:55.901Z,1557165175.901 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:52:56.295Z,1557165176.295 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:56.694Z,1557165176.694 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:57.094Z,1557165177.094 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:57.502Z,1557165177.502 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:57.902Z,1557165177.902 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:58.310Z,1557165178.310 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:58.721Z,1557165178.721 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:58.772Z,1557165178.772 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:52:58.772Z,1557165178.772 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:52:58.772Z,1557165178.772 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:52:58.772Z,1557165178.772 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater] Running Loop=2
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:52:58.773Z,1557165178.773 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:52:58.774Z,1557165178.774 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:52:58.774Z,1557165178.774 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:52:58.774Z,1557165178.774 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:52:59.114Z,1557165179.114 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:59.531Z,1557165179.531 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:52:59.926Z,1557165179.926 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:00.326Z,1557165180.326 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:00.761Z,1557165180.761 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.263087
2019-05-06T17:53:00.761Z,1557165180.761 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:00.761Z,1557165180.761 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:00.762Z,1557165180.762 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:00.763Z,1557165180.763 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:01.146Z,1557165181.146 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:01.147Z,1557165181.147 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:01.147Z,1557165181.147 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:01.161Z,1557165181.161 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:01.542Z,1557165181.542 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:01.942Z,1557165181.942 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:02.350Z,1557165182.350 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:02.754Z,1557165182.754 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:03.154Z,1557165183.154 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:03.562Z,1557165183.562 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:03.962Z,1557165183.962 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:04.366Z,1557165184.366 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:04.774Z,1557165184.774 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:05.174Z,1557165185.174 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:05.578Z,1557165185.578 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:05.997Z,1557165185.997 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.234839
2019-05-06T17:53:05.997Z,1557165185.997 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:05.997Z,1557165185.997 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:05.998Z,1557165185.998 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:05.999Z,1557165185.999 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:06.390Z,1557165186.390 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:06.390Z,1557165186.390 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:06.391Z,1557165186.391 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:06.409Z,1557165186.409 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:06.798Z,1557165186.798 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:07.194Z,1557165187.194 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:07.602Z,1557165187.602 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:08.003Z,1557165188.003 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:08.412Z,1557165188.412 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:08.834Z,1557165188.834 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:09.218Z,1557165189.218 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:09.246Z,1557165189.246 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:53:09.246Z,1557165189.246 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:53:09.246Z,1557165189.246 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater] Running Loop=3
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:53:09.247Z,1557165189.247 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:53:09.248Z,1557165189.248 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:53:09.618Z,1557165189.618 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:10.030Z,1557165190.030 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:10.426Z,1557165190.426 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:10.830Z,1557165190.830 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:11.249Z,1557165191.249 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.250875
2019-05-06T17:53:11.249Z,1557165191.249 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:11.249Z,1557165191.249 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:11.250Z,1557165191.250 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:11.251Z,1557165191.251 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:11.642Z,1557165191.642 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:11.643Z,1557165191.643 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:11.643Z,1557165191.643 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:11.657Z,1557165191.657 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:12.042Z,1557165192.042 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:12.450Z,1557165192.450 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:12.854Z,1557165192.854 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:13.262Z,1557165193.262 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:13.666Z,1557165193.666 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:14.066Z,1557165194.066 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:14.470Z,1557165194.470 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:14.874Z,1557165194.874 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:15.278Z,1557165195.278 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:15.678Z,1557165195.678 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:16.082Z,1557165196.082 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:16.497Z,1557165196.497 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.246982
2019-05-06T17:53:16.497Z,1557165196.497 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:16.497Z,1557165196.497 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:16.498Z,1557165196.498 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:16.499Z,1557165196.499 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:16.890Z,1557165196.890 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:16.890Z,1557165196.890 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:16.891Z,1557165196.891 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:16.906Z,1557165196.906 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:17.298Z,1557165197.298 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:17.320Z,1557165197.320 [Micromodem](ERROR): Response from modem unexpected: $CACST,6,1,20190506175314.786497,06,304,12,0091,0150,246,00,00,02,02,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,198,-0.05,-999,9760,4000*7B

2019-05-06T17:53:17.706Z,1557165197.706 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:18.102Z,1557165198.102 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:18.506Z,1557165198.506 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:18.910Z,1557165198.910 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:19.318Z,1557165199.318 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:19.733Z,1557165199.733 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:19.784Z,1557165199.784 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:53:19.784Z,1557165199.784 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:53:19.784Z,1557165199.784 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:53:19.786Z,1557165199.786 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:53:19.786Z,1557165199.786 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:53:19.786Z,1557165199.786 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:53:19.786Z,1557165199.786 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:53:19.786Z,1557165199.786 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:53:19.786Z,1557165199.786 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-05-06T17:53:19.786Z,1557165199.786 [DUSBL:RequestRepeater] Running Loop=4
2019-05-06T17:53:19.787Z,1557165199.787 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:53:19.787Z,1557165199.787 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:53:19.787Z,1557165199.787 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:53:19.787Z,1557165199.787 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:53:19.787Z,1557165199.787 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:53:20.130Z,1557165200.130 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:20.538Z,1557165200.538 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:20.934Z,1557165200.934 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:21.338Z,1557165201.338 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:21.773Z,1557165201.773 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.275121
2019-05-06T17:53:21.773Z,1557165201.773 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:21.773Z,1557165201.773 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:21.774Z,1557165201.774 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:21.775Z,1557165201.775 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:22.142Z,1557165202.142 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:22.142Z,1557165202.142 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:22.143Z,1557165202.143 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:22.158Z,1557165202.158 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:22.550Z,1557165202.550 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:22.954Z,1557165202.954 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:23.354Z,1557165203.354 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:23.761Z,1557165203.761 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:24.166Z,1557165204.166 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:24.570Z,1557165204.570 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:24.974Z,1557165204.974 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:25.378Z,1557165205.378 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:25.778Z,1557165205.778 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:26.186Z,1557165206.186 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:26.606Z,1557165206.606 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:27.021Z,1557165207.021 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.246793
2019-05-06T17:53:27.021Z,1557165207.021 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:27.021Z,1557165207.021 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:27.022Z,1557165207.022 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:27.023Z,1557165207.023 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:27.399Z,1557165207.399 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:27.399Z,1557165207.399 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:27.399Z,1557165207.399 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:27.413Z,1557165207.413 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:27.798Z,1557165207.798 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:28.219Z,1557165208.219 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:28.610Z,1557165208.610 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:29.026Z,1557165209.026 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:29.418Z,1557165209.418 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:29.824Z,1557165209.824 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:30.238Z,1557165210.238 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:30.294Z,1557165210.294 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:53:30.294Z,1557165210.294 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:53:30.294Z,1557165210.294 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:53:30.295Z,1557165210.295 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:53:30.295Z,1557165210.295 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:53:30.295Z,1557165210.295 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:53:30.295Z,1557165210.295 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater] Running Loop=5
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:53:30.296Z,1557165210.296 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:53:30.634Z,1557165210.634 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:31.038Z,1557165211.038 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:31.438Z,1557165211.438 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:31.838Z,1557165211.838 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:32.253Z,1557165212.253 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.230882
2019-05-06T17:53:32.253Z,1557165212.253 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:32.253Z,1557165212.253 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:32.254Z,1557165212.254 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:32.255Z,1557165212.255 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:32.650Z,1557165212.650 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:32.650Z,1557165212.650 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:32.651Z,1557165212.651 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:32.665Z,1557165212.665 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:33.054Z,1557165213.054 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:33.462Z,1557165213.462 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:33.858Z,1557165213.858 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:34.262Z,1557165214.262 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:34.666Z,1557165214.666 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:34.667Z,1557165214.667 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-06T17:53:35.070Z,1557165215.070 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:35.478Z,1557165215.478 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:35.493Z,1557165215.493 [NAL9602](DEBUG): Fix Requested
2019-05-06T17:53:35.882Z,1557165215.882 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:36.286Z,1557165216.286 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:36.690Z,1557165216.690 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:37.090Z,1557165217.090 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:37.521Z,1557165217.521 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.267163
2019-05-06T17:53:37.521Z,1557165217.521 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:37.521Z,1557165217.521 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:37.522Z,1557165217.522 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:37.523Z,1557165217.523 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:37.906Z,1557165217.906 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:37.906Z,1557165217.906 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:37.907Z,1557165217.907 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:37.922Z,1557165217.922 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:38.306Z,1557165218.306 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:38.710Z,1557165218.710 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:39.114Z,1557165219.114 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:39.514Z,1557165219.514 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:39.918Z,1557165219.918 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:40.330Z,1557165220.330 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:40.757Z,1557165220.757 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:41.134Z,1557165221.134 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:41.182Z,1557165221.182 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:53:41.182Z,1557165221.182 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:53:41.182Z,1557165221.182 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:53:41.183Z,1557165221.183 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:53:41.183Z,1557165221.183 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:53:41.183Z,1557165221.183 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:53:41.183Z,1557165221.183 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:53:41.183Z,1557165221.183 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:53:41.183Z,1557165221.183 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-05-06T17:53:41.183Z,1557165221.183 [DUSBL:RequestRepeater] Running Loop=6
2019-05-06T17:53:41.184Z,1557165221.184 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:53:41.184Z,1557165221.184 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:53:41.184Z,1557165221.184 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:53:41.184Z,1557165221.184 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:53:41.184Z,1557165221.184 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:53:41.538Z,1557165221.538 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:41.939Z,1557165221.939 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:41.953Z,1557165221.953 [NAL9602](DEBUG): Fix Requested
2019-05-06T17:53:42.342Z,1557165222.342 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:42.345Z,1557165222.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175309.00,A,3648.16397,N,12147.28358,W,0.156,295.96,060519,,,A*7B
2019-05-06T17:53:42.348Z,1557165222.348 [NAL9602](INFO): GPS fix at 20190506T175309: (36.802733, -121.788060)
2019-05-06T17:53:42.777Z,1557165222.777 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.254790
2019-05-06T17:53:42.777Z,1557165222.777 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:42.777Z,1557165222.777 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:42.778Z,1557165222.778 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:42.779Z,1557165222.779 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:43.158Z,1557165223.158 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:43.158Z,1557165223.158 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:43.158Z,1557165223.158 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:43.173Z,1557165223.173 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:43.568Z,1557165223.568 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:43.970Z,1557165223.970 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:44.374Z,1557165224.374 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:44.774Z,1557165224.774 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:45.178Z,1557165225.178 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:45.582Z,1557165225.582 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:45.986Z,1557165225.986 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:46.390Z,1557165226.390 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:46.799Z,1557165226.799 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:47.198Z,1557165227.198 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:47.602Z,1557165227.602 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:48.017Z,1557165228.017 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.239017
2019-05-06T17:53:48.017Z,1557165228.017 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:48.017Z,1557165228.017 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:48.017Z,1557165228.017 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:48.040Z,1557165228.040 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:48.040Z,1557165228.040 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:48.040Z,1557165228.040 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:48.078Z,1557165228.078 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:48.410Z,1557165228.410 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:48.814Z,1557165228.814 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:49.222Z,1557165229.222 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:49.622Z,1557165229.622 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:50.026Z,1557165230.026 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:50.430Z,1557165230.430 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:50.834Z,1557165230.834 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:51.242Z,1557165231.242 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:51.646Z,1557165231.646 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:51.684Z,1557165231.684 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:53:51.684Z,1557165231.684 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:53:51.684Z,1557165231.684 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:53:51.701Z,1557165231.701 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:53:51.702Z,1557165231.702 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:53:51.702Z,1557165231.702 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:53:51.702Z,1557165231.702 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:53:51.702Z,1557165231.702 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:53:51.702Z,1557165231.702 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-05-06T17:53:51.702Z,1557165231.702 [DUSBL:RequestRepeater] Running Loop=7
2019-05-06T17:53:51.703Z,1557165231.703 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:53:51.703Z,1557165231.703 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:53:51.703Z,1557165231.703 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:53:51.703Z,1557165231.703 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:53:51.703Z,1557165231.703 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:53:52.046Z,1557165232.046 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:52.450Z,1557165232.450 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:52.854Z,1557165232.854 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:53.281Z,1557165233.281 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.263191
2019-05-06T17:53:53.281Z,1557165233.281 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:53.281Z,1557165233.281 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:53.282Z,1557165233.282 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:53.283Z,1557165233.283 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:53.662Z,1557165233.662 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:53.662Z,1557165233.662 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:53.663Z,1557165233.663 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:53.678Z,1557165233.678 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:54.066Z,1557165234.066 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:54.470Z,1557165234.470 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:54.874Z,1557165234.874 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:55.278Z,1557165235.278 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:55.686Z,1557165235.686 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:56.086Z,1557165236.086 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:56.490Z,1557165236.490 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:56.894Z,1557165236.894 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:57.302Z,1557165237.302 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:57.706Z,1557165237.706 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:58.106Z,1557165238.106 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:58.521Z,1557165238.521 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.239011
2019-05-06T17:53:58.521Z,1557165238.521 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:53:58.521Z,1557165238.521 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:53:58.521Z,1557165238.521 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:53:58.522Z,1557165238.522 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:58.914Z,1557165238.914 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:58.914Z,1557165238.914 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:53:58.914Z,1557165238.914 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:53:58.929Z,1557165238.929 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:53:59.318Z,1557165239.318 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:53:59.738Z,1557165239.738 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:00.142Z,1557165240.142 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:00.534Z,1557165240.534 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:00.938Z,1557165240.938 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:01.338Z,1557165241.338 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:01.763Z,1557165241.763 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:02.150Z,1557165242.150 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:02.201Z,1557165242.201 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:54:02.201Z,1557165242.201 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:54:02.201Z,1557165242.201 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:54:02.202Z,1557165242.202 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:54:02.202Z,1557165242.202 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:54:02.202Z,1557165242.202 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:54:02.202Z,1557165242.202 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:54:02.202Z,1557165242.202 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:54:02.202Z,1557165242.202 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-05-06T17:54:02.203Z,1557165242.203 [DUSBL:RequestRepeater] Running Loop=8
2019-05-06T17:54:02.203Z,1557165242.203 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:54:02.203Z,1557165242.203 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:54:02.203Z,1557165242.203 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:54:02.203Z,1557165242.203 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:54:02.203Z,1557165242.203 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:54:02.554Z,1557165242.554 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:02.958Z,1557165242.958 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:03.379Z,1557165243.379 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:03.777Z,1557165243.777 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.255700
2019-05-06T17:54:03.778Z,1557165243.778 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:54:03.778Z,1557165243.778 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:54:03.778Z,1557165243.778 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:54:03.778Z,1557165243.778 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:04.170Z,1557165244.170 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:04.577Z,1557165244.577 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:04.983Z,1557165244.983 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:05.386Z,1557165245.386 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:05.790Z,1557165245.790 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:06.190Z,1557165246.190 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:06.590Z,1557165246.590 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:06.994Z,1557165246.994 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:07.398Z,1557165247.398 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:07.802Z,1557165247.802 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:08.210Z,1557165248.210 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:08.610Z,1557165248.610 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:09.029Z,1557165249.029 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.250812
2019-05-06T17:54:09.029Z,1557165249.029 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:54:09.029Z,1557165249.029 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:54:09.030Z,1557165249.030 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:54:09.030Z,1557165249.030 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:09.422Z,1557165249.422 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:09.822Z,1557165249.822 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:10.226Z,1557165250.226 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:10.630Z,1557165250.630 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:11.038Z,1557165251.038 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:11.438Z,1557165251.438 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:11.842Z,1557165251.842 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:12.250Z,1557165252.250 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:12.650Z,1557165252.650 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:12.753Z,1557165252.753 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:54:12.753Z,1557165252.753 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:54:12.753Z,1557165252.753 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:54:12.754Z,1557165252.754 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:54:12.754Z,1557165252.754 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:54:12.754Z,1557165252.754 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:54:12.754Z,1557165252.754 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:54:12.754Z,1557165252.754 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:54:12.754Z,1557165252.754 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-05-06T17:54:12.755Z,1557165252.755 [DUSBL:RequestRepeater] Running Loop=9
2019-05-06T17:54:12.755Z,1557165252.755 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:54:12.755Z,1557165252.755 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:54:12.755Z,1557165252.755 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:54:12.755Z,1557165252.755 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:54:12.755Z,1557165252.755 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:54:13.054Z,1557165253.054 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:13.458Z,1557165253.458 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:13.866Z,1557165253.866 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:14.277Z,1557165254.277 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.247177
2019-05-06T17:54:14.277Z,1557165254.277 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:54:14.277Z,1557165254.277 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:54:14.278Z,1557165254.278 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:54:14.278Z,1557165254.278 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:14.670Z,1557165254.670 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:14.675Z,1557165254.675 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-06T17:54:15.074Z,1557165255.074 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:15.478Z,1557165255.478 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:15.882Z,1557165255.882 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:16.286Z,1557165256.286 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:16.700Z,1557165256.700 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:17.094Z,1557165257.094 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:17.502Z,1557165257.502 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:17.902Z,1557165257.902 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:18.306Z,1557165258.306 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:18.742Z,1557165258.742 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:19.118Z,1557165259.118 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:19.529Z,1557165259.529 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.251398
2019-05-06T17:54:19.529Z,1557165259.529 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:54:19.529Z,1557165259.529 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:54:19.530Z,1557165259.530 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:54:19.532Z,1557165259.532 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:19.922Z,1557165259.922 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:20.330Z,1557165260.330 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:20.754Z,1557165260.754 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:21.132Z,1557165261.132 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:21.538Z,1557165261.538 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:21.942Z,1557165261.942 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:22.350Z,1557165262.350 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:22.763Z,1557165262.763 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:23.158Z,1557165263.158 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:23.217Z,1557165263.217 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:54:23.217Z,1557165263.217 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:54:23.218Z,1557165263.218 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:54:23.218Z,1557165263.218 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:54:23.218Z,1557165263.218 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:54:23.218Z,1557165263.218 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:54:23.218Z,1557165263.218 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:54:23.218Z,1557165263.218 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:54:23.219Z,1557165263.219 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-05-06T17:54:23.219Z,1557165263.219 [DUSBL:RequestRepeater] Running Loop=10
2019-05-06T17:54:23.219Z,1557165263.219 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-05-06T17:54:23.219Z,1557165263.219 [DUSBL:RequestRepeater:A] Running Loop=1
2019-05-06T17:54:23.219Z,1557165263.219 [DUSBL:RequestRepeater:B] Running Loop=1
2019-05-06T17:54:23.219Z,1557165263.219 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-05-06T17:54:23.219Z,1557165263.219 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:54:23.558Z,1557165263.558 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:23.966Z,1557165263.966 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:24.370Z,1557165264.370 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:24.781Z,1557165264.781 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.250550
2019-05-06T17:54:24.781Z,1557165264.781 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:54:24.781Z,1557165264.781 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:54:24.782Z,1557165264.782 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:54:24.783Z,1557165264.783 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:25.174Z,1557165265.174 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:25.174Z,1557165265.174 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:54:25.174Z,1557165265.174 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:54:25.191Z,1557165265.191 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:54:25.586Z,1557165265.586 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:25.587Z,1557165265.587 [Micromodem](ERROR): Response from modem unexpected: $CADQF,188,1*51

2019-05-06T17:54:25.589Z,1557165265.589 [Micromodem](ERROR): Response from modem unexpected: $CAMSG,BAD_CRC,0*21

2019-05-06T17:54:25.982Z,1557165265.982 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:25.996Z,1557165265.996 [Micromodem](ERROR): Response from modem unexpected: $CACST,6,1,20190506175423.645197,06,136,09,0100,0150,246,00,00,02,02,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,188,0.10,-999,9760,4000*5B

2019-05-06T17:54:26.390Z,1557165266.390 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:26.790Z,1557165266.790 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:27.198Z,1557165267.198 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:27.602Z,1557165267.602 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:28.001Z,1557165268.001 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:28.406Z,1557165268.406 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:28.810Z,1557165268.810 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:29.220Z,1557165269.220 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:29.618Z,1557165269.618 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:30.037Z,1557165270.037 [DUSBL_Hydroid](INFO): Setting waiting for range response to false due to timeout. Elapsed:5.254924
2019-05-06T17:54:30.037Z,1557165270.037 [DUSBL_Hydroid](INFO): ****** received transponder code query ******
2019-05-06T17:54:30.037Z,1557165270.037 [DUSBL_Hydroid](INFO): ****** received ping request ******
2019-05-06T17:54:30.038Z,1557165270.038 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-05-06T17:54:30.039Z,1557165270.039 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:30.430Z,1557165270.430 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:30.430Z,1557165270.430 [DUSBL_Hydroid](INFO): Requesting micromodem ping code 2
2019-05-06T17:54:30.430Z,1557165270.430 [DUSBL_Hydroid](INFO): Arming DUSBL
2019-05-06T17:54:30.445Z,1557165270.445 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-05-06T17:54:30.834Z,1557165270.834 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:31.238Z,1557165271.238 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:31.642Z,1557165271.642 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:32.042Z,1557165272.042 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:32.446Z,1557165272.446 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:32.850Z,1557165272.850 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:33.254Z,1557165273.254 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:33.662Z,1557165273.662 [DUSBL_Hydroid](INFO): In Read and Parse
2019-05-06T17:54:33.686Z,1557165273.686 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-05-06T17:54:33.686Z,1557165273.686 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-05-06T17:54:33.686Z,1557165273.686 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:54:33.687Z,1557165273.687 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-05-06T17:54:33.687Z,1557165273.687 [DUSBL:RequestRepeater] Stopped
2019-05-06T17:54:33.687Z,1557165273.687 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-05-06T17:54:33.687Z,1557165273.687 [DUSBL:RequestRepeater:A] Stopped
2019-05-06T17:54:33.687Z,1557165273.687 [DUSBL:RequestRepeater:B] Stopped
2019-05-06T17:54:33.688Z,1557165273.688 [DUSBL](INFO): Completed DUSBL
2019-05-06T17:54:33.688Z,1557165273.688 [MissionManager](INFO): DUSBL is completed.
2019-05-06T17:54:33.688Z,1557165273.688 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-05-06T17:54:33.688Z,1557165273.688 [DUSBL] Stopped
2019-05-06T17:54:33.688Z,1557165273.688 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-05-06T17:54:33.709Z,1557165273.709 [DUSBL:A.Pitch] Stopped
2019-05-06T17:54:33.709Z,1557165273.709 [DUSBL:B.SetSpeed] Stopped
2019-05-06T17:54:33.709Z,1557165273.709 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-05-06T17:54:33.709Z,1557165273.709 [DUSBL:C] Stopped
2019-05-06T17:54:34.095Z,1557165274.095 [MissionManager](IMPORTANT): Started mission Default
2019-05-06T17:54:34.095Z,1557165274.095 [Default] Running Loop=1
2019-05-06T17:54:34.095Z,1557165274.095 [Default](DEBUG): Aggregate::initialize Default
2019-05-06T17:54:34.095Z,1557165274.095 [Default:B.GoToSurface] Running Loop=1
2019-05-06T17:54:34.095Z,1557165274.095 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-06T17:54:34.096Z,1557165274.096 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-06T17:54:34.096Z,1557165274.096 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-06T17:54:34.096Z,1557165274.096 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-06T17:54:34.097Z,1557165274.097 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-06T17:54:34.097Z,1557165274.097 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-06T17:54:34.098Z,1557165274.098 [Default:A.Wait] Running Loop=1
2019-05-06T17:54:34.098Z,1557165274.098 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:54:47.436Z,1557165287.436 [Default:A.Wait](INFO): Done Waiting.
2019-05-06T17:54:47.454Z,1557165287.454 [Default:A.Wait] Stopped
2019-05-06T17:54:47.454Z,1557165287.454 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:54:47.839Z,1557165287.839 [Default:CheckIn] Running Loop=1
2019-05-06T17:54:47.839Z,1557165287.839 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-06T17:54:47.840Z,1557165287.840 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-06T17:54:49.437Z,1557165289.437 [NAL9602](DEBUG): Fix Requested
2019-05-06T17:54:49.845Z,1557165289.845 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175416.00,A,3648.16175,N,12147.28701,W,0.194,295.96,060519,,,A*7A
2019-05-06T17:54:49.847Z,1557165289.847 [NAL9602](INFO): GPS fix at 20190506T175416: (36.802696, -121.788117)
2019-05-06T17:54:50.076Z,1557165290.076 [Default:CheckIn:Read_GPS] Stopped
2019-05-06T17:54:50.076Z,1557165290.076 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-06T17:54:50.290Z,1557165290.290 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-06T17:54:51.561Z,1557165291.561 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20190506T174744/Courier0004.lzma
2019-05-06T17:54:52.270Z,1557165292.270 [DataOverHttps](INFO): Moved sent file to Logs/20190506T174744/Courier0004.lzma.bak
2019-05-06T17:54:52.270Z,1557165292.270 [DataOverHttps](INFO): SBD MOMSN=10942528
2019-05-06T17:55:04.346Z,1557165304.346 [DataOverHttps](INFO): Sending 1076 bytes from file Logs/20190506T174744/Express0005.lzma
2019-05-06T17:55:05.150Z,1557165305.150 [DataOverHttps](INFO): Moved sent file to Logs/20190506T174744/Express0005.lzma.bak
2019-05-06T17:55:05.150Z,1557165305.150 [DataOverHttps](INFO): SBD MOMSN=10942531
2019-05-06T17:55:05.908Z,1557165305.908 [Default:CheckIn:Read_Iridium] Stopped
2019-05-06T17:55:05.908Z,1557165305.908 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-06T17:55:05.908Z,1557165305.908 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-06T17:55:18.811Z,1557165318.811 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-05-06T17:55:18.815Z,1557165318.815 [BPC1](INFO): Received data from all battery sticks.
2019-05-06T17:55:20.387Z,1557165320.387 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-05-06T17:55:20.472Z,1557165320.472 [NAL9602](FAULT): received: 
+CSQ:0

OK07, 2, 0, 0, 0

OK
2019-05-06T17:55:20.473Z,1557165320.473 [NAL9602] Data Fault, FailCount= 1
2019-05-06T17:55:20.473Z,1557165320.473 [NAL9602](ERROR): Data Fault
2019-05-06T17:55:20.569Z,1557165320.569 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-06T17:55:20.791Z,1557165320.791 [NAL9602](INFO): Powering down
2019-05-06T17:55:21.634Z,1557165321.634 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-06T17:55:21.634Z,1557165321.634 [NAL9602] No Fault, FailCount= 1
2019-05-06T17:55:28.891Z,1557165328.891 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,  96.92,  92.93,   0.00, 103.91
2019-05-06T17:55:51.084Z,1557165351.084 [NAL9602](INFO): Powering up NAL9602
2019-05-06T17:56:02.007Z,1557165362.007 [NAL9602](INFO): NAL9602 initialized
2019-05-06T17:56:33.107Z,1557165393.107 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-06T17:57:41.231Z,1557165461.231 [CommandLine](IMPORTANT): got command restart application
2019-05-06T17:57:42.241Z,1557165462.241 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-06T17:57:42.241Z,1557165462.241 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:42.242Z,1557165462.242 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.345Z,1557165462.345 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-06T17:57:42.345Z,1557165462.345 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.346Z,1557165462.346 [CommandLine](INFO): Join timeout helper Thread ID is 3207
2019-05-06T17:57:42.346Z,1557165462.346 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-06T17:57:42.346Z,1557165462.346 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.347Z,1557165462.347 [NavChartDb](INFO): Join timeout helper Thread ID is 3208
2019-05-06T17:57:42.465Z,1557165462.465 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:42.465Z,1557165462.465 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.485Z,1557165462.485 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-05-06T17:57:42.485Z,1557165462.485 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.485Z,1557165462.485 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 3209
2019-05-06T17:57:42.489Z,1557165462.489 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:42.489Z,1557165462.489 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-06T17:57:42.490Z,1557165462.490 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.505Z,1557165462.505 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-06T17:57:42.505Z,1557165462.505 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.505Z,1557165462.505 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 3210
2019-05-06T17:57:42.557Z,1557165462.557 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:42.557Z,1557165462.557 [CTD_NeilBrown](INFO): Powering down
2019-05-06T17:57:42.569Z,1557165462.569 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.569Z,1557165462.569 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-06T17:57:42.569Z,1557165462.569 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.570Z,1557165462.570 [Radio_Surface](INFO): Join timeout helper Thread ID is 3211
2019-05-06T17:57:42.897Z,1557165462.897 [Radio_Surface](INFO): Powering down
2019-05-06T17:57:42.898Z,1557165462.898 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:42.898Z,1557165462.898 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.910Z,1557165462.910 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-06T17:57:42.910Z,1557165462.910 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:42.910Z,1557165462.910 [DataOverHttps](INFO): Join timeout helper Thread ID is 3212
2019-05-06T17:57:43.145Z,1557165463.145 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:43.145Z,1557165463.145 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.150Z,1557165463.150 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-06T17:57:43.150Z,1557165463.150 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.150Z,1557165463.150 [logger](INFO): Join timeout helper Thread ID is 3213
2019-05-06T17:57:43.157Z,1557165463.157 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:43.157Z,1557165463.157 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.170Z,1557165463.170 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-06T17:57:43.170Z,1557165463.170 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.170Z,1557165463.170 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-06T17:57:43.170Z,1557165463.170 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.170Z,1557165463.170 [controlThread](INFO): Join timeout helper Thread ID is 3214
2019-05-06T17:57:43.377Z,1557165463.377 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-06T17:57:43.377Z,1557165463.377 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-06T17:57:43.378Z,1557165463.378 [AHRS_M2](INFO): Powering down
2019-05-06T17:57:43.449Z,1557165463.449 [DUSBL_Hydroid](INFO): Powering down
2019-05-06T17:57:43.521Z,1557165463.521 [Micromodem](INFO): Powering down
2019-05-06T17:57:43.617Z,1557165463.617 [NAL9602](INFO): Powering down
2019-05-06T17:57:43.689Z,1557165463.689 [RDI_Pathfinder](INFO): Powering down
2019-05-06T17:57:43.690Z,1557165463.690 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-06T17:57:43.691Z,1557165463.691 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-06T17:57:43.692Z,1557165463.692 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-06T17:57:43.692Z,1557165463.692 [MissionManager](INFO): Uninitializing Mission Default
2019-05-06T17:57:43.692Z,1557165463.692 [Default] Stopped
2019-05-06T17:57:43.692Z,1557165463.692 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-06T17:57:43.692Z,1557165463.692 [Default:B.GoToSurface] Stopped
2019-05-06T17:57:43.692Z,1557165463.692 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-06T17:57:43.692Z,1557165463.692 [Default:CheckIn] Stopped
2019-05-06T17:57:43.693Z,1557165463.693 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-06T17:57:43.693Z,1557165463.693 [Default:CheckIn:C.Wait] Stopped
2019-05-06T17:57:43.693Z,1557165463.693 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-06T17:57:43.695Z,1557165463.695 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-06T17:57:43.695Z,1557165463.695 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-06T17:57:43.696Z,1557165463.696 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-06T17:57:43.696Z,1557165463.696 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-06T17:57:43.696Z,1557165463.696 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-06T17:57:43.696Z,1557165463.696 [BuoyancyServo](INFO): Powering down
2019-05-06T17:57:43.709Z,1557165463.709 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-06T17:57:43.709Z,1557165463.709 [ElevatorServo](INFO): Powering down
2019-05-06T17:57:43.710Z,1557165463.710 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-06T17:57:43.710Z,1557165463.710 [MassServo](INFO): Powering down
2019-05-06T17:57:43.711Z,1557165463.711 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-06T17:57:43.711Z,1557165463.711 [RudderServo](INFO): Powering down
2019-05-06T17:57:43.712Z,1557165463.712 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-06T17:57:43.712Z,1557165463.712 [ThrusterServo](INFO): Powering down
2019-05-06T17:57:43.713Z,1557165463.713 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-06T17:57:43.713Z,1557165463.713 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-06T17:57:43.713Z,1557165463.713 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-06T17:57:43.713Z,1557165463.713 [CBIT](DEBUG): Powering off loads.
2019-05-06T17:57:43.725Z,1557165463.725 [CBIT](DEBUG): Disabling WDT.
2019-05-06T17:57:43.737Z,1557165463.737 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-06T17:57:43.738Z,1557165463.738 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.785Z,1557165463.785 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.794Z,1557165463.794 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.838Z,1557165463.838 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.840Z,1557165463.840 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.894Z,1557165463.894 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-06T17:57:43.964Z,1557165463.964 [logger ThreadHandler](INFO): Thread cancelled.