2019-05-30T16:43:39.187Z,1559234619.187 [Supervisor](DEBUG): Initializing supervisor.
2019-05-30T16:43:39.189Z,1559234619.189 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-30T16:43:39.190Z,1559234619.190 [SyncHandler](INFO): Protected caller Thread ID is 613
2019-05-30T16:43:39.190Z,1559234619.190 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-30T16:43:39.191Z,1559234619.191 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-30T16:43:39.192Z,1559234619.192 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 614
2019-05-30T16:43:39.194Z,1559234619.194 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-30T16:43:39.252Z,1559234619.252 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-30T16:43:39.253Z,1559234619.253 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-30T16:43:39.254Z,1559234619.254 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 615
2019-05-30T16:43:39.254Z,1559234619.254 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-30T16:43:39.255Z,1559234619.255 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-30T16:43:39.256Z,1559234619.256 [logger ThreadHandler](INFO): Protected caller Thread ID is 616
2019-05-30T16:43:39.258Z,1559234619.258 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-30T16:43:39.258Z,1559234619.258 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-30T16:43:39.260Z,1559234619.260 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-30T16:43:39.696Z,1559234619.696 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-30T16:43:39.696Z,1559234619.696 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-30T16:43:39.795Z,1559234619.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-30T16:43:39.796Z,1559234619.796 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-30T16:43:40.124Z,1559234620.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-30T16:43:40.124Z,1559234620.124 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-30T16:43:40.268Z,1559234620.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-30T16:43:40.268Z,1559234620.268 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-30T16:43:40.462Z,1559234620.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-30T16:43:40.463Z,1559234620.463 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-30T16:43:40.922Z,1559234620.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-30T16:43:40.922Z,1559234620.922 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-30T16:43:41.135Z,1559234621.135 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-30T16:43:41.136Z,1559234621.136 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-30T16:43:41.283Z,1559234621.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-30T16:43:41.284Z,1559234621.284 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-30T16:43:41.480Z,1559234621.480 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-30T16:43:41.481Z,1559234621.481 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-30T16:43:41.578Z,1559234621.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-30T16:43:41.579Z,1559234621.579 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-30T16:43:41.904Z,1559234621.904 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-30T16:43:41.904Z,1559234621.904 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-30T16:43:41.986Z,1559234621.986 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-30T16:43:42.091Z,1559234622.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-30T16:43:42.092Z,1559234622.092 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-30T16:43:42.698Z,1559234622.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-30T16:43:42.698Z,1559234622.698 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-30T16:43:43.091Z,1559234623.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-30T16:43:43.093Z,1559234623.093 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-30T16:43:43.094Z,1559234623.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-30T16:43:43.310Z,1559234623.310 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-30T16:43:43.413Z,1559234623.413 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-30T16:43:43.513Z,1559234623.513 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-30T16:43:43.743Z,1559234623.743 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-30T16:43:43.744Z,1559234623.744 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-30T16:43:43.830Z,1559234623.830 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-30T16:43:43.934Z,1559234623.934 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-30T16:43:44.261Z,1559234624.261 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-30T16:43:44.513Z,1559234624.513 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-30T16:43:44.744Z,1559234624.744 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-30T16:43:45.027Z,1559234625.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-30T16:43:45.162Z,1559234625.162 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/LOGIN/
2019-05-30T16:43:45.162Z,1559234625.162 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-30T16:43:45.176Z,1559234625.176 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-30T16:43:45.552Z,1559234625.552 [AHRS_M2] Loaded
2019-05-30T16:43:45.552Z,1559234625.552 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-30T16:43:45.566Z,1559234625.566 [Depth_Keller] Loaded
2019-05-30T16:43:45.566Z,1559234625.566 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-30T16:43:45.571Z,1559234625.571 [DropWeight] Loaded
2019-05-30T16:43:45.572Z,1559234625.572 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-30T16:43:45.628Z,1559234625.628 [DUSBL_Hydroid] Loaded
2019-05-30T16:43:45.629Z,1559234625.629 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-30T16:43:45.676Z,1559234625.676 [Micromodem] Loaded
2019-05-30T16:43:45.676Z,1559234625.676 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-30T16:43:45.774Z,1559234625.774 [NAL9602] Loaded
2019-05-30T16:43:45.774Z,1559234625.774 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-30T16:43:45.790Z,1559234625.790 [Onboard] Loaded
2019-05-30T16:43:45.790Z,1559234625.790 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-30T16:43:45.796Z,1559234625.796 [PowerOnly] Loaded
2019-05-30T16:43:45.796Z,1559234625.796 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-30T16:43:45.806Z,1559234625.806 [Radio_Surface] Loaded
2019-05-30T16:43:45.806Z,1559234625.806 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-30T16:43:45.808Z,1559234625.808 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407644E0
2019-05-30T16:43:45.808Z,1559234625.808 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 695
2019-05-30T16:43:45.852Z,1559234625.852 [RDI_Pathfinder] Loaded
2019-05-30T16:43:45.852Z,1559234625.852 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-30T16:43:47.339Z,1559234627.339 [BPC1] Loaded
2019-05-30T16:43:47.339Z,1559234627.339 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-30T16:43:47.340Z,1559234627.340 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-30T16:43:47.340Z,1559234627.340 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-30T16:43:47.353Z,1559234627.353 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-30T16:43:47.354Z,1559234627.354 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-30T16:43:47.458Z,1559234627.458 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-30T16:43:47.458Z,1559234627.458 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-30T16:43:47.479Z,1559234627.479 [NavChart] Loaded
2019-05-30T16:43:47.479Z,1559234627.479 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-30T16:43:47.483Z,1559234627.483 [UniversalFixResidualReporter] Loaded
2019-05-30T16:43:47.483Z,1559234627.483 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-30T16:43:47.484Z,1559234627.484 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-30T16:43:47.484Z,1559234627.484 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-30T16:43:47.590Z,1559234627.590 [BuoyancyServo] Loaded
2019-05-30T16:43:47.590Z,1559234627.590 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-30T16:43:47.605Z,1559234627.605 [ElevatorServo] Loaded
2019-05-30T16:43:47.606Z,1559234627.606 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-30T16:43:47.620Z,1559234627.620 [MassServo] Loaded
2019-05-30T16:43:47.621Z,1559234627.621 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-30T16:43:47.636Z,1559234627.636 [RudderServo] Loaded
2019-05-30T16:43:47.636Z,1559234627.636 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-30T16:43:47.650Z,1559234627.650 [ThrusterServo] Loaded
2019-05-30T16:43:47.651Z,1559234627.651 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-30T16:43:47.651Z,1559234627.651 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-30T16:43:47.652Z,1559234627.652 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-30T16:43:47.897Z,1559234627.897 [CTD_NeilBrown] Loaded
2019-05-30T16:43:47.898Z,1559234627.898 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-30T16:43:47.899Z,1559234627.899 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408A64E0
2019-05-30T16:43:47.899Z,1559234627.899 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 696
2019-05-30T16:43:47.943Z,1559234627.943 [WetLabsSeaOWL_UV_A] Loaded
2019-05-30T16:43:47.944Z,1559234627.944 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-30T16:43:47.945Z,1559234627.945 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408D64E0
2019-05-30T16:43:47.945Z,1559234627.945 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 697
2019-05-30T16:43:47.946Z,1559234627.946 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-30T16:43:47.946Z,1559234627.946 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-30T16:43:48.238Z,1559234628.238 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-30T16:43:48.238Z,1559234628.238 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-30T16:43:48.278Z,1559234628.278 [DepthRateCalculator] Loaded
2019-05-30T16:43:48.278Z,1559234628.278 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-30T16:43:48.284Z,1559234628.284 [PitchRateCalculator] Loaded
2019-05-30T16:43:48.284Z,1559234628.284 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-30T16:43:48.296Z,1559234628.296 [SpeedCalculator] Loaded
2019-05-30T16:43:48.296Z,1559234628.296 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-30T16:43:48.317Z,1559234628.317 [TempGradientCalculator] Loaded
2019-05-30T16:43:48.317Z,1559234628.317 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-30T16:43:48.323Z,1559234628.323 [YawRateCalculator] Loaded
2019-05-30T16:43:48.323Z,1559234628.323 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-30T16:43:48.363Z,1559234628.363 [ElevatorOffsetCalculator] Loaded
2019-05-30T16:43:48.363Z,1559234628.363 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-30T16:43:48.364Z,1559234628.364 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-30T16:43:48.364Z,1559234628.364 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-30T16:43:48.499Z,1559234628.499 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-30T16:43:48.520Z,1559234628.520 [SBIT] Loaded
2019-05-30T16:43:48.521Z,1559234628.521 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-30T16:43:48.521Z,1559234628.521 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-30T16:43:48.533Z,1559234628.533 [IBIT] Loaded
2019-05-30T16:43:48.533Z,1559234628.533 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-30T16:43:48.536Z,1559234628.536 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-30T16:43:48.673Z,1559234628.673 [CBIT] Loaded
2019-05-30T16:43:48.673Z,1559234628.673 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-30T16:43:48.674Z,1559234628.674 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-30T16:43:48.674Z,1559234628.674 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-30T16:43:48.743Z,1559234628.743 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-30T16:43:48.744Z,1559234628.744 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-30T16:43:48.843Z,1559234628.843 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-30T16:43:48.843Z,1559234628.843 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-30T16:43:48.908Z,1559234628.908 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-30T16:43:48.991Z,1559234628.991 [VerticalControl] Loaded
2019-05-30T16:43:48.992Z,1559234628.992 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-30T16:43:48.992Z,1559234628.992 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-30T16:43:49.049Z,1559234629.049 [HorizontalControl] Loaded
2019-05-30T16:43:49.050Z,1559234629.050 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-30T16:43:49.050Z,1559234629.050 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-30T16:43:49.052Z,1559234629.052 [SpeedControl] Loaded
2019-05-30T16:43:49.052Z,1559234629.052 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-30T16:43:49.053Z,1559234629.053 [LoopControl](DEBUG): Construct LoopControl.
2019-05-30T16:43:49.054Z,1559234629.054 [LoopControl] Loaded
2019-05-30T16:43:49.054Z,1559234629.054 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-30T16:43:49.054Z,1559234629.054 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-30T16:43:49.055Z,1559234629.055 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-30T16:43:49.192Z,1559234629.192 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-30T16:43:49.201Z,1559234629.201 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-30T16:43:49.203Z,1559234629.203 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-30T16:43:49.213Z,1559234629.213 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-30T16:43:49.214Z,1559234629.214 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AAD4E0
2019-05-30T16:43:49.214Z,1559234629.214 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 698
2019-05-30T16:43:49.275Z,1559234629.275 [Supervisor](INFO): Main Thread ID is 612
2019-05-30T16:43:49.275Z,1559234629.275 [Supervisor](DEBUG): Running supervisor.
2019-05-30T16:43:49.276Z,1559234629.276 [CommandLine ThreadHandler](INFO): Handler Thread ID is 699
2019-05-30T16:43:49.278Z,1559234629.278 [controlThread ThreadHandler](INFO): Handler Thread ID is 700
2019-05-30T16:43:49.279Z,1559234629.279 [controlThread](DEBUG): Initializing ControlThread
2019-05-30T16:43:49.287Z,1559234629.287 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-30T16:43:49.288Z,1559234629.288 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-30T16:43:49.289Z,1559234629.289 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-30T16:43:49.289Z,1559234629.289 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-30T16:43:49.290Z,1559234629.290 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-30T16:43:49.290Z,1559234629.290 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-30T16:43:49.291Z,1559234629.291 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-30T16:43:49.291Z,1559234629.291 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-30T16:43:49.292Z,1559234629.292 [SBIT](INFO): Initialize SBIT Component.
2019-05-30T16:43:49.292Z,1559234629.292 [SBIT](IMPORTANT): git: 2019-05-01-19-g6ef4ecc
2019-05-30T16:43:49.293Z,1559234629.293 [SBIT](INFO): git hash: 6ef4ecc926d3cc84e5878e2d73d98fd38ff7dcf7
2019-05-30T16:43:49.293Z,1559234629.293 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-30T16:43:49.294Z,1559234629.294 [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-30T16:43:49.295Z,1559234629.295 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-05-30T16:43:49.296Z,1559234629.296 [IBIT](INFO): Initialize IBIT Component.
2019-05-30T16:43:49.297Z,1559234629.297 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-30T16:43:49.298Z,1559234629.298 [logger ThreadHandler](INFO): Handler Thread ID is 701
2019-05-30T16:43:49.311Z,1559234629.311 [CBIT](DEBUG): Initialized mux pins.
2019-05-30T16:43:49.311Z,1559234629.311 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-30T16:43:49.316Z,1559234629.316 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 702
2019-05-30T16:43:49.324Z,1559234629.324 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 703
2019-05-30T16:43:49.325Z,1559234629.325 [CTD_NeilBrown](INFO): Powering down
2019-05-30T16:43:49.335Z,1559234629.335 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-30T16:43:49.335Z,1559234629.335 [CBIT](DEBUG): Initializing heartbeat.
2019-05-30T16:43:49.364Z,1559234629.364 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 704
2019-05-30T16:43:49.364Z,1559234629.364 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T16:43:49.395Z,1559234629.395 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 705
2019-05-30T16:43:49.399Z,1559234629.399 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-30T16:43:49.399Z,1559234629.399 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-30T16:43:49.399Z,1559234629.399 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-30T16:43:49.399Z,1559234629.399 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-30T16:43:49.399Z,1559234629.399 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-30T16:43:49.400Z,1559234629.400 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-30T16:43:49.400Z,1559234629.400 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-30T16:43:49.400Z,1559234629.400 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-30T16:43:49.400Z,1559234629.400 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-30T16:43:49.400Z,1559234629.400 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-30T16:43:49.400Z,1559234629.400 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-30T16:43:49.401Z,1559234629.401 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-30T16:43:49.401Z,1559234629.401 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-30T16:43:49.401Z,1559234629.401 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-30T16:43:49.401Z,1559234629.401 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-30T16:43:49.401Z,1559234629.401 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-30T16:43:49.407Z,1559234629.407 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-30T16:43:49.407Z,1559234629.407 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-30T16:43:49.443Z,1559234629.443 [CBIT](DEBUG): Backplane powered.
2019-05-30T16:43:49.443Z,1559234629.443 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-30T16:43:49.445Z,1559234629.445 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-30T16:43:49.446Z,1559234629.446 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-30T16:43:49.446Z,1559234629.446 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-30T16:43:49.447Z,1559234629.447 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-30T16:43:49.457Z,1559234629.457 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T16:43:49.484Z,1559234629.484 [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-30T16:43:49.485Z,1559234629.485 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-30T16:43:49.544Z,1559234629.544 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-30T16:43:49.545Z,1559234629.545 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-30T16:43:49.547Z,1559234629.547 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T16:43:49.589Z,1559234629.589 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-30T16:43:49.608Z,1559234629.608 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-30T16:43:49.613Z,1559234629.613 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-30T16:43:49.633Z,1559234629.633 [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-30T16:43:49.637Z,1559234629.637 [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-30T16:43:49.651Z,1559234629.651 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-30T16:43:49.719Z,1559234629.719 [Radio_Surface](INFO): Powering up
2019-05-30T16:43:49.785Z,1559234629.785 [DUSBL_Hydroid](INFO): Powering up
2019-05-30T16:43:49.786Z,1559234629.786 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-30T16:43:49.815Z,1559234629.815 [Micromodem](INFO): Start
2019-05-30T16:43:49.877Z,1559234629.877 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:43:49.883Z,1559234629.883 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-30T16:43:49.884Z,1559234629.884 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:43:49.891Z,1559234629.891 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-30T16:43:49.892Z,1559234629.892 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:43:49.899Z,1559234629.899 [MassServo](DEBUG): Initializing MassServo.
2019-05-30T16:43:49.900Z,1559234629.900 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:43:49.907Z,1559234629.907 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T16:43:49.908Z,1559234629.908 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:43:49.915Z,1559234629.915 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-30T16:43:50.061Z,1559234630.061 [Micromodem](INFO): Starting
2019-05-30T16:43:50.062Z,1559234630.062 [Micromodem](INFO): Powering up
2019-05-30T16:43:50.062Z,1559234630.062 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-30T16:43:50.452Z,1559234630.452 [Micromodem](INFO): Starting
2019-05-30T16:43:50.807Z,1559234630.807 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-30T16:43:50.807Z,1559234630.807 [RudderServo](FAULT): Rudder failed to initialize
2019-05-30T16:43:50.807Z,1559234630.807 [RudderServo] Communications Fault, FailCount= 1
2019-05-30T16:43:50.807Z,1559234630.807 [RudderServo](ERROR): Communications Fault
2019-05-30T16:43:50.918Z,1559234630.918 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-30T16:43:50.929Z,1559234630.929 [Micromodem](INFO): Starting
2019-05-30T16:43:51.076Z,1559234631.076 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-30T16:43:51.076Z,1559234631.076 [RudderServo](INFO): Powering down
2019-05-30T16:43:51.333Z,1559234631.333 [Micromodem](INFO): Starting
2019-05-30T16:43:51.740Z,1559234631.740 [Micromodem](INFO): Starting
2019-05-30T16:43:51.767Z,1559234631.767 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:43:51.888Z,1559234631.888 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T16:43:51.892Z,1559234631.892 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-30T16:43:51.892Z,1559234631.892 [RudderServo] No Fault, FailCount= 1
2019-05-30T16:43:52.141Z,1559234632.141 [Micromodem](INFO): Starting
2019-05-30T16:43:52.544Z,1559234632.544 [Micromodem](INFO): Starting
2019-05-30T16:43:53.017Z,1559234633.017 [Micromodem](INFO): Starting
2019-05-30T16:43:53.377Z,1559234633.377 [Micromodem](INFO): Starting
2019-05-30T16:43:53.781Z,1559234633.781 [Micromodem](INFO): Starting
2019-05-30T16:43:54.253Z,1559234634.253 [Micromodem](INFO): Starting
2019-05-30T16:43:54.601Z,1559234634.601 [Micromodem](INFO): Starting
2019-05-30T16:43:55.005Z,1559234635.005 [Micromodem](INFO): Starting
2019-05-30T16:43:55.005Z,1559234635.005 [Micromodem](INFO): Starting
2019-05-30T16:43:55.006Z,1559234635.006 [Micromodem](DEBUG): Nmea buf: $CCCFG,ALL,0*33

2019-05-30T16:43:55.006Z,1559234635.006 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-05-30T16:43:55.006Z,1559234635.006 [Micromodem](DEBUG): Nmea buf: $CCCFG,SRC,1*31

2019-05-30T16:43:55.007Z,1559234635.007 [Micromodem](DEBUG): Nmea buf: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-05-30T16:43:55.007Z,1559234635.007 [Micromodem](DEBUG): Nmea buf: $CCCFG,nav.nst,1*4D

2019-05-30T16:43:55.009Z,1559234635.009 [Micromodem](DEBUG): Nmea buf: $CCCFG,DTO,20*1F

2019-05-30T16:43:55.010Z,1559234635.010 [Micromodem](DEBUG): Nmea buf: $CCCFG,FC0,10000*46

2019-05-30T16:43:55.011Z,1559234635.011 [Micromodem](DEBUG): Nmea buf: $CCCFG,BW0,4000*63

2019-05-30T16:43:55.013Z,1559234635.013 [Micromodem](DEBUG): Nmea buf: $CCCFG,BND,0*3A

2019-05-30T16:43:55.409Z,1559234635.409 [Micromodem](INFO): Starting
2019-05-30T16:43:55.813Z,1559234635.813 [Micromodem](INFO): Starting
2019-05-30T16:43:56.205Z,1559234636.205 [Micromodem](INFO): Starting
2019-05-30T16:43:56.621Z,1559234636.621 [Micromodem](INFO): Starting
2019-05-30T16:43:57.025Z,1559234637.025 [Micromodem](INFO): Starting
2019-05-30T16:43:57.429Z,1559234637.429 [Micromodem](INFO): Starting
2019-05-30T16:43:57.821Z,1559234637.821 [Micromodem](INFO): Starting
2019-05-30T16:43:58.229Z,1559234638.229 [Micromodem](INFO): Starting
2019-05-30T16:43:58.618Z,1559234638.618 [Micromodem](INFO): Starting
2019-05-30T16:43:59.029Z,1559234639.029 [Micromodem](INFO): Starting
2019-05-30T16:43:59.425Z,1559234639.425 [Micromodem](INFO): Starting
2019-05-30T16:43:59.824Z,1559234639.824 [Micromodem](INFO): Starting
2019-05-30T16:44:00.253Z,1559234640.253 [Micromodem](INFO): Starting
2019-05-30T16:44:00.629Z,1559234640.629 [Micromodem](INFO): Starting
2019-05-30T16:44:01.029Z,1559234641.029 [Micromodem](INFO): Starting
2019-05-30T16:44:01.433Z,1559234641.433 [Micromodem](INFO): Starting
2019-05-30T16:44:01.433Z,1559234641.433 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-05-30T16:44:01.434Z,1559234641.434 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-05-30T16:44:01.837Z,1559234641.837 [Micromodem](INFO): Starting
2019-05-30T16:44:02.241Z,1559234642.241 [Micromodem](INFO): Starting
2019-05-30T16:44:02.645Z,1559234642.645 [Micromodem](INFO): Starting
2019-05-30T16:44:03.049Z,1559234643.049 [Micromodem](INFO): Starting
2019-05-30T16:44:03.076Z,1559234643.076 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T16:44:03.453Z,1559234643.453 [Micromodem](INFO): Starting
2019-05-30T16:44:03.861Z,1559234643.861 [Micromodem](INFO): Starting
2019-05-30T16:44:04.261Z,1559234644.261 [Micromodem](INFO): Starting
2019-05-30T16:44:04.665Z,1559234644.665 [Micromodem](INFO): Starting
2019-05-30T16:44:05.069Z,1559234645.069 [Micromodem](INFO): Starting
2019-05-30T16:44:05.473Z,1559234645.473 [Micromodem](INFO): Starting
2019-05-30T16:44:05.885Z,1559234645.885 [Micromodem](INFO): Starting
2019-05-30T16:44:06.285Z,1559234646.285 [Micromodem](INFO): Starting
2019-05-30T16:44:06.689Z,1559234646.689 [Micromodem](INFO): Starting
2019-05-30T16:44:07.090Z,1559234647.090 [Micromodem](INFO): Starting
2019-05-30T16:44:07.497Z,1559234647.497 [Micromodem](INFO): Starting
2019-05-30T16:44:07.897Z,1559234647.897 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-30T16:44:07.911Z,1559234647.911 [Micromodem](INFO): Starting
2019-05-30T16:44:08.306Z,1559234648.306 [Micromodem](INFO): Starting
2019-05-30T16:44:08.709Z,1559234648.709 [Micromodem](INFO): Starting
2019-05-30T16:44:09.113Z,1559234649.113 [Micromodem](INFO): Starting
2019-05-30T16:44:09.512Z,1559234649.512 [Micromodem](INFO): Starting
2019-05-30T16:44:09.921Z,1559234649.921 [Micromodem](INFO): Starting
2019-05-30T16:44:10.320Z,1559234650.320 [Micromodem](INFO): Starting
2019-05-30T16:44:10.724Z,1559234650.724 [Micromodem](INFO): Starting
2019-05-30T16:44:11.128Z,1559234651.128 [Micromodem](INFO): Starting
2019-05-30T16:44:11.537Z,1559234651.537 [Micromodem](INFO): Starting
2019-05-30T16:44:11.537Z,1559234651.537 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-05-30T16:44:11.538Z,1559234651.538 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-05-30T16:44:11.936Z,1559234651.936 [Micromodem](INFO): Starting
2019-05-30T16:44:12.340Z,1559234652.340 [Micromodem](INFO): Starting
2019-05-30T16:44:12.756Z,1559234652.756 [Micromodem](INFO): Starting
2019-05-30T16:44:13.148Z,1559234653.148 [Micromodem](INFO): Starting
2019-05-30T16:44:13.557Z,1559234653.557 [Micromodem](INFO): Starting
2019-05-30T16:44:13.956Z,1559234653.956 [Micromodem](INFO): Starting
2019-05-30T16:44:14.360Z,1559234654.360 [Micromodem](INFO): Starting
2019-05-30T16:44:14.764Z,1559234654.764 [Micromodem](INFO): Starting
2019-05-30T16:44:15.168Z,1559234655.168 [Micromodem](INFO): Starting
2019-05-30T16:44:15.572Z,1559234655.572 [Micromodem](INFO): Starting
2019-05-30T16:44:15.981Z,1559234655.981 [Micromodem](INFO): Starting
2019-05-30T16:44:15.982Z,1559234655.982 [NAL9602](INFO): Powering up NAL9602
2019-05-30T16:44:16.380Z,1559234656.380 [Micromodem](INFO): Starting
2019-05-30T16:44:16.785Z,1559234656.785 [Micromodem](INFO): Starting
2019-05-30T16:44:17.188Z,1559234657.188 [Micromodem](INFO): Starting
2019-05-30T16:44:17.597Z,1559234657.597 [Micromodem](INFO): Starting
2019-05-30T16:44:18.023Z,1559234658.023 [Micromodem](INFO): Starting
2019-05-30T16:44:18.400Z,1559234658.400 [Micromodem](INFO): Starting
2019-05-30T16:44:18.805Z,1559234658.805 [Micromodem](INFO): Starting
2019-05-30T16:44:19.208Z,1559234659.208 [Micromodem](INFO): Starting
2019-05-30T16:44:19.612Z,1559234659.612 [Micromodem](INFO): Starting
2019-05-30T16:44:20.030Z,1559234660.030 [Micromodem](INFO): Starting
2019-05-30T16:44:20.420Z,1559234660.420 [Micromodem](INFO): Starting
2019-05-30T16:44:20.824Z,1559234660.824 [Micromodem](INFO): Starting
2019-05-30T16:44:21.235Z,1559234661.235 [Micromodem](INFO): Starting
2019-05-30T16:44:21.632Z,1559234661.632 [Micromodem](INFO): Starting
2019-05-30T16:44:21.634Z,1559234661.634 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-05-30T16:44:21.634Z,1559234661.634 [Micromodem](INFO): Nmea out: $CCCFG,nav.nst,1*4D

2019-05-30T16:44:22.041Z,1559234662.041 [Micromodem](INFO): Starting
2019-05-30T16:44:22.440Z,1559234662.440 [Micromodem](INFO): Starting
2019-05-30T16:44:22.844Z,1559234662.844 [Micromodem](INFO): Starting
2019-05-30T16:44:23.248Z,1559234663.248 [Micromodem](INFO): Starting
2019-05-30T16:44:23.652Z,1559234663.652 [Micromodem](INFO): Starting
2019-05-30T16:44:24.056Z,1559234664.056 [Micromodem](INFO): Starting
2019-05-30T16:44:24.460Z,1559234664.460 [Micromodem](INFO): Starting
2019-05-30T16:44:24.872Z,1559234664.872 [Micromodem](INFO): Starting
2019-05-30T16:44:25.268Z,1559234665.268 [Micromodem](INFO): Starting
2019-05-30T16:44:25.672Z,1559234665.672 [Micromodem](INFO): Starting
2019-05-30T16:44:26.076Z,1559234666.076 [Micromodem](INFO): Starting
2019-05-30T16:44:26.480Z,1559234666.480 [Micromodem](INFO): Starting
2019-05-30T16:44:26.885Z,1559234666.885 [Micromodem](INFO): Starting
2019-05-30T16:44:26.885Z,1559234666.885 [NAL9602](INFO): NAL9602 initialized
2019-05-30T16:44:27.288Z,1559234667.288 [Micromodem](INFO): Starting
2019-05-30T16:44:27.692Z,1559234667.692 [Micromodem](INFO): Starting
2019-05-30T16:44:27.707Z,1559234667.707 [NAL9602](DEBUG): Fix Requested
2019-05-30T16:44:28.124Z,1559234668.124 [Micromodem](INFO): Starting
2019-05-30T16:44:28.500Z,1559234668.500 [Micromodem](INFO): Starting
2019-05-30T16:44:28.904Z,1559234668.904 [Micromodem](INFO): Starting
2019-05-30T16:44:28.933Z,1559234668.933 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-30T16:44:28.938Z,1559234668.938 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T16:44:29.308Z,1559234669.308 [Micromodem](INFO): Starting
2019-05-30T16:44:29.712Z,1559234669.712 [Micromodem](INFO): Starting
2019-05-30T16:44:30.116Z,1559234670.116 [Micromodem](INFO): Starting
2019-05-30T16:44:30.529Z,1559234670.529 [Micromodem](INFO): Starting
2019-05-30T16:44:30.933Z,1559234670.933 [Micromodem](INFO): Starting
2019-05-30T16:44:31.436Z,1559234671.436 [Micromodem](INFO): Starting
2019-05-30T16:44:31.436Z,1559234671.436 [Micromodem](INFO): Nmea in: $CACFG,nav.nst,1*4F

2019-05-30T16:44:31.437Z,1559234671.437 [Micromodem](INFO): Nmea out: $CCCFG,DTO,20*1F

2019-05-30T16:44:31.836Z,1559234671.836 [Micromodem](INFO): Starting
2019-05-30T16:44:32.240Z,1559234672.240 [Micromodem](INFO): Starting
2019-05-30T16:44:32.644Z,1559234672.644 [Micromodem](INFO): Starting
2019-05-30T16:44:33.052Z,1559234673.052 [Micromodem](INFO): Starting
2019-05-30T16:44:33.452Z,1559234673.452 [Micromodem](INFO): Starting
2019-05-30T16:44:33.856Z,1559234673.856 [Micromodem](INFO): Starting
2019-05-30T16:44:34.264Z,1559234674.264 [Micromodem](INFO): Starting
2019-05-30T16:44:34.668Z,1559234674.668 [Micromodem](INFO): Starting
2019-05-30T16:44:35.068Z,1559234675.068 [Micromodem](INFO): Starting
2019-05-30T16:44:35.472Z,1559234675.472 [Micromodem](INFO): Starting
2019-05-30T16:44:35.876Z,1559234675.876 [Micromodem](INFO): Starting
2019-05-30T16:44:36.280Z,1559234676.280 [Micromodem](INFO): Starting
2019-05-30T16:44:36.684Z,1559234676.684 [Micromodem](INFO): Starting
2019-05-30T16:44:37.096Z,1559234677.096 [Micromodem](INFO): Starting
2019-05-30T16:44:37.496Z,1559234677.496 [Micromodem](INFO): Starting
2019-05-30T16:44:37.900Z,1559234677.900 [Micromodem](INFO): Starting
2019-05-30T16:44:38.300Z,1559234678.300 [Micromodem](INFO): Starting
2019-05-30T16:44:38.704Z,1559234678.704 [Micromodem](INFO): Starting
2019-05-30T16:44:39.108Z,1559234679.108 [Micromodem](INFO): Starting
2019-05-30T16:44:39.512Z,1559234679.512 [Micromodem](INFO): Starting
2019-05-30T16:44:39.916Z,1559234679.916 [Micromodem](INFO): Starting
2019-05-30T16:44:40.040Z,1559234680.040 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.013400
CHAN A1 (24V): -0.026001
CHAN A2 (12V): -0.006250
CHAN A3 (5V): -0.001992
CHAN B0 (3.3V): 0.000023
CHAN B1 (3.15aV): 0.000169
CHAN B2 (3.15bV): 0.000370
CHAN B3 (GND): 0.001783
OPEN: 0.007278
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T16:44:40.320Z,1559234680.320 [Micromodem](INFO): Starting
2019-05-30T16:44:40.724Z,1559234680.724 [Micromodem](INFO): Starting
2019-05-30T16:44:41.128Z,1559234681.128 [Micromodem](INFO): Starting
2019-05-30T16:44:41.544Z,1559234681.544 [Micromodem](INFO): Starting
2019-05-30T16:44:41.545Z,1559234681.545 [Micromodem](INFO): Nmea in: $CACFG,DTO,20*1D

2019-05-30T16:44:41.545Z,1559234681.545 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2019-05-30T16:44:41.936Z,1559234681.936 [Micromodem](INFO): Starting
2019-05-30T16:44:42.340Z,1559234682.340 [Micromodem](INFO): Starting
2019-05-30T16:44:42.744Z,1559234682.744 [Micromodem](INFO): Starting
2019-05-30T16:44:43.152Z,1559234683.152 [Micromodem](INFO): Starting
2019-05-30T16:44:43.552Z,1559234683.552 [Micromodem](INFO): Starting
2019-05-30T16:44:43.960Z,1559234683.960 [Micromodem](INFO): Starting
2019-05-30T16:44:44.536Z,1559234684.536 [Micromodem](INFO): Starting
2019-05-30T16:44:44.933Z,1559234684.933 [Micromodem](INFO): Starting
2019-05-30T16:44:45.353Z,1559234685.353 [Micromodem](INFO): Starting
2019-05-30T16:44:45.746Z,1559234685.746 [Micromodem](INFO): Starting
2019-05-30T16:44:46.150Z,1559234686.150 [Micromodem](INFO): Starting
2019-05-30T16:44:46.554Z,1559234686.554 [Micromodem](INFO): Starting
2019-05-30T16:44:46.957Z,1559234686.957 [Micromodem](INFO): Starting
2019-05-30T16:44:47.371Z,1559234687.371 [Micromodem](INFO): Starting
2019-05-30T16:44:47.760Z,1559234687.760 [Micromodem](INFO): Starting
2019-05-30T16:44:48.168Z,1559234688.168 [Micromodem](INFO): Starting
2019-05-30T16:44:48.572Z,1559234688.572 [Micromodem](INFO): Starting
2019-05-30T16:44:48.983Z,1559234688.983 [Micromodem](INFO): Starting
2019-05-30T16:44:49.376Z,1559234689.376 [Micromodem](INFO): Starting
2019-05-30T16:44:49.396Z,1559234689.396 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T16:44:49.397Z,1559234689.397 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053009541365,35.0, -0.1,   0.0,1448.9,,  0.00,   0.00,   0.00,   0.00,   0.00
2019-05-30T16:44:49.784Z,1559234689.784 [Micromodem](INFO): Starting
2019-05-30T16:44:50.188Z,1559234690.188 [Micromodem](INFO): Starting
2019-05-30T16:44:50.596Z,1559234690.596 [Micromodem](INFO): Starting
2019-05-30T16:44:51.002Z,1559234691.002 [Micromodem](INFO): Starting
2019-05-30T16:44:51.400Z,1559234691.400 [Micromodem](INFO): Starting
2019-05-30T16:44:51.401Z,1559234691.401 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2019-05-30T16:44:51.402Z,1559234691.402 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2019-05-30T16:44:51.800Z,1559234691.800 [Micromodem](INFO): Starting
2019-05-30T16:44:52.205Z,1559234692.205 [Micromodem](INFO): Starting
2019-05-30T16:44:52.613Z,1559234692.613 [Micromodem](INFO): Starting
2019-05-30T16:44:53.029Z,1559234693.029 [Micromodem](INFO): Starting
2019-05-30T16:44:53.416Z,1559234693.416 [Micromodem](INFO): Starting
2019-05-30T16:44:53.825Z,1559234693.825 [Micromodem](INFO): Starting
2019-05-30T16:44:54.232Z,1559234694.232 [Micromodem](INFO): Starting
2019-05-30T16:44:54.629Z,1559234694.629 [Micromodem](INFO): Starting
2019-05-30T16:44:55.037Z,1559234695.037 [Micromodem](INFO): Starting
2019-05-30T16:44:55.444Z,1559234695.444 [Micromodem](INFO): Starting
2019-05-30T16:44:55.844Z,1559234695.844 [Micromodem](INFO): Starting
2019-05-30T16:44:56.248Z,1559234696.248 [Micromodem](INFO): Starting
2019-05-30T16:44:56.652Z,1559234696.652 [Micromodem](INFO): Starting
2019-05-30T16:44:57.059Z,1559234697.059 [Micromodem](INFO): Starting
2019-05-30T16:44:57.464Z,1559234697.464 [Micromodem](INFO): Starting
2019-05-30T16:44:57.868Z,1559234697.868 [Micromodem](INFO): Starting
2019-05-30T16:44:58.264Z,1559234698.264 [Micromodem](INFO): Starting
2019-05-30T16:44:58.672Z,1559234698.672 [Micromodem](INFO): Starting
2019-05-30T16:44:59.076Z,1559234699.076 [Micromodem](INFO): Starting
2019-05-30T16:44:59.480Z,1559234699.480 [Micromodem](INFO): Starting
2019-05-30T16:44:59.884Z,1559234699.884 [Micromodem](INFO): Starting
2019-05-30T16:45:00.292Z,1559234700.292 [Micromodem](INFO): Starting
2019-05-30T16:45:00.688Z,1559234700.688 [Micromodem](INFO): Starting
2019-05-30T16:45:01.092Z,1559234701.092 [Micromodem](INFO): Starting
2019-05-30T16:45:01.496Z,1559234701.496 [Micromodem](INFO): Starting
2019-05-30T16:45:01.497Z,1559234701.497 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2019-05-30T16:45:01.497Z,1559234701.497 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2019-05-30T16:45:01.900Z,1559234701.900 [Micromodem](INFO): Starting
2019-05-30T16:45:02.309Z,1559234702.309 [Micromodem](INFO): Starting
2019-05-30T16:45:02.708Z,1559234702.708 [Micromodem](INFO): Starting
2019-05-30T16:45:03.112Z,1559234703.112 [Micromodem](INFO): Starting
2019-05-30T16:45:03.524Z,1559234703.524 [Micromodem](INFO): Starting
2019-05-30T16:45:03.920Z,1559234703.920 [Micromodem](INFO): Starting
2019-05-30T16:45:04.324Z,1559234704.324 [Micromodem](INFO): Starting
2019-05-30T16:45:04.728Z,1559234704.728 [Micromodem](INFO): Starting
2019-05-30T16:45:05.137Z,1559234705.137 [Micromodem](INFO): Starting
2019-05-30T16:45:05.537Z,1559234705.537 [Micromodem](INFO): Starting
2019-05-30T16:45:05.945Z,1559234705.945 [Micromodem](INFO): Starting
2019-05-30T16:45:06.349Z,1559234706.349 [Micromodem](INFO): Starting
2019-05-30T16:45:06.759Z,1559234706.759 [Micromodem](INFO): Starting
2019-05-30T16:45:07.157Z,1559234707.157 [Micromodem](INFO): Starting
2019-05-30T16:45:07.561Z,1559234707.561 [Micromodem](INFO): Starting
2019-05-30T16:45:07.965Z,1559234707.965 [Micromodem](INFO): Starting
2019-05-30T16:45:08.365Z,1559234708.365 [Micromodem](INFO): Starting
2019-05-30T16:45:08.773Z,1559234708.773 [Micromodem](INFO): Starting
2019-05-30T16:45:09.177Z,1559234709.177 [Micromodem](INFO): Starting
2019-05-30T16:45:09.581Z,1559234709.581 [Micromodem](INFO): Starting
2019-05-30T16:45:09.996Z,1559234709.996 [Micromodem](INFO): Starting
2019-05-30T16:45:10.388Z,1559234710.388 [Micromodem](INFO): Starting
2019-05-30T16:45:10.788Z,1559234710.788 [Micromodem](INFO): Starting
2019-05-30T16:45:11.360Z,1559234711.360 [Micromodem](INFO): Starting
2019-05-30T16:45:11.361Z,1559234711.361 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2019-05-30T16:45:11.362Z,1559234711.362 [Micromodem](DEBUG): Nmea buf: $CCCLK,2019,05,30,16,45,12*4D

2019-05-30T16:45:11.362Z,1559234711.362 [Micromodem](INFO): Nmea out: $CCCLK,2019,05,30,16,45,12*4D

2019-05-30T16:45:11.764Z,1559234711.764 [Micromodem](INFO): Starting
2019-05-30T16:45:12.171Z,1559234712.171 [Micromodem](INFO): Starting
2019-05-30T16:45:12.568Z,1559234712.568 [Micromodem](INFO): Starting
2019-05-30T16:45:12.569Z,1559234712.569 [Micromodem](INFO): Nmea in: $CACLK,2019,5,30,16,45,12*7F

2019-05-30T16:45:12.571Z,1559234712.571 [Micromodem](INFO): Nmea in: $CATMS,0,2019-05-30T16:45:13Z*7E

2019-05-30T16:45:21.462Z,1559234721.462 [Micromodem](INFO): Nmea in: $CATMG,2019-05-30T16:45:13Z,USER_CMD,RTC*37

2019-05-30T16:45:22.324Z,1559234722.324 [SBIT](IMPORTANT): SBIT PASSED
2019-05-30T16:45:22.399Z,1559234722.399 [CommandLine](IMPORTANT): got command configSet list
2019-05-30T16:45:22.400Z,1559234722.400 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-30T16:45:22.400Z,1559234722.400 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=40 count;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-05-30T16:45:22.401Z,1559234722.401 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-05-30T16:45:22.402Z,1559234722.402 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;

2019-05-30T16:45:22.402Z,1559234722.402 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;

2019-05-30T16:45:22.402Z,1559234722.402 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-30T16:45:22.402Z,1559234722.402 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;

2019-05-30T16:45:22.402Z,1559234722.402 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-05-30T16:45:22.709Z,1559234722.709 [MissionManager](IMPORTANT): Started mission Startup
2019-05-30T16:45:22.709Z,1559234722.709 [Startup] Running Loop=1
2019-05-30T16:45:22.709Z,1559234722.709 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-30T16:45:22.709Z,1559234722.709 [Startup:A.GoToSurface] Running Loop=1
2019-05-30T16:45:22.709Z,1559234722.709 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T16:45:22.710Z,1559234722.710 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T16:45:22.710Z,1559234722.710 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T16:45:22.710Z,1559234722.710 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T16:45:22.715Z,1559234722.715 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T16:45:22.716Z,1559234722.716 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T16:45:22.717Z,1559234722.717 [Startup:StartupSatComms] Running Loop=1
2019-05-30T16:45:22.717Z,1559234722.717 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-30T16:45:22.717Z,1559234722.717 [Startup:StartupSatComms:A] Running Loop=1
2019-05-30T16:45:23.130Z,1559234723.130 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-30T16:45:58.463Z,1559234758.463 [CommandLine](IMPORTANT): got command show stack
2019-05-30T16:45:58.464Z,1559234758.464 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-30T16:45:58.464Z,1559234758.464 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2019-05-30T16:45:58.464Z,1559234758.464 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:A
2019-05-30T16:46:22.900Z,1559234782.900 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-30T16:45:22.7Z
2019-05-30T16:46:22.900Z,1559234782.900 [Startup:StartupSatComms:A] Stopped
2019-05-30T16:46:22.901Z,1559234782.901 [Startup:StartupSatComms:B] Running Loop=1
2019-05-30T16:46:23.345Z,1559234783.345 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T16:46:23.709Z,1559234783.709 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 0
2019-05-30T16:46:24.366Z,1559234784.366 [Startup:StartupSatComms:B] Stopped
2019-05-30T16:46:24.366Z,1559234784.366 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-30T16:46:24.366Z,1559234784.366 [Startup:StartupSatComms] Stopped
2019-05-30T16:46:24.366Z,1559234784.366 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-30T16:46:24.367Z,1559234784.367 [Startup](INFO): Completed Startup
2019-05-30T16:46:24.367Z,1559234784.367 [MissionManager](INFO): Startup is completed.
2019-05-30T16:46:24.367Z,1559234784.367 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-30T16:46:24.367Z,1559234784.367 [Startup] Stopped
2019-05-30T16:46:24.367Z,1559234784.367 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-30T16:46:24.367Z,1559234784.367 [Startup:A.GoToSurface] Stopped
2019-05-30T16:46:24.367Z,1559234784.367 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T16:46:24.469Z,1559234784.469 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T16:46:24.469Z,1559234784.469 [Default] Running Loop=1
2019-05-30T16:46:24.469Z,1559234784.469 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T16:46:24.469Z,1559234784.469 [Default:B.GoToSurface] Running Loop=1
2019-05-30T16:46:24.469Z,1559234784.469 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T16:46:24.469Z,1559234784.469 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T16:46:24.470Z,1559234784.470 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T16:46:24.470Z,1559234784.470 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T16:46:24.470Z,1559234784.470 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T16:46:24.471Z,1559234784.471 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T16:46:24.479Z,1559234784.479 [Default:A.Wait] Running Loop=1
2019-05-30T16:46:24.479Z,1559234784.479 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T16:46:37.760Z,1559234797.760 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T16:46:37.761Z,1559234797.761 [Default:A.Wait] Stopped
2019-05-30T16:46:37.761Z,1559234797.761 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T16:46:38.175Z,1559234798.175 [Default:CheckIn] Running Loop=1
2019-05-30T16:46:38.175Z,1559234798.175 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T16:46:38.175Z,1559234798.175 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T16:46:38.561Z,1559234798.561 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-30T16:46:47.823Z,1559234807.823 [CommandLine](IMPORTANT): got command run ./Missions/Insert/MicromodemComms.xml
2019-05-30T16:46:47.824Z,1559234807.824 [MissionManager](INFO): Loading Mission: ./Missions/Insert/MicromodemComms.xml
2019-05-30T16:46:47.840Z,1559234807.840 [MissionManager](INFO): DefineArg MicromodemComms.Timeout = 10.000000 min
2019-05-30T16:46:47.843Z,1559234807.843 [MissionManager](INFO): DefineArg MicromodemComms.CommsInterval = 5.000000 min
2019-05-30T16:46:47.849Z,1559234807.849 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Aggregate 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="MicromodemComms">
       
    <Description>
        Triggers periodic uModem comms.
    </Description>

    <DefineArg Name="Timeout"><Units:minute/><Value>10</Value></DefineArg>
    
    <DefineArg Name="CommsInterval"><Description>
        The timing is based on the variable Universal:platform_communications
    </Description><Units:minute/><Value>5</Value></DefineArg>
    
    <When>
        <Called/>
        <Or>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt>
                <Arg Name="CommsInterval"/>
            </Gt>
        </Or>
    </When>

    <Aggregate Id="CheckIn">

        <Sequence/>

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

    </Aggregate>

</Aggregate>


2019-05-30T16:46:47.851Z,1559234807.851 [CommandLine](IMPORTANT): Running ./Missions/Insert/MicromodemComms.xml
2019-05-30T16:46:48.086Z,1559234808.086 [Default] Stopped
2019-05-30T16:46:48.086Z,1559234808.086 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-30T16:46:48.086Z,1559234808.086 [Default:B.GoToSurface] Stopped
2019-05-30T16:46:48.086Z,1559234808.086 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T16:46:48.086Z,1559234808.086 [Default:CheckIn] Stopped
2019-05-30T16:46:48.086Z,1559234808.086 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T16:46:48.086Z,1559234808.086 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T16:46:48.086Z,1559234808.086 [MissionManager](IMPORTANT): Started mission MicromodemComms
2019-05-30T16:46:48.087Z,1559234808.087 [MicromodemComms] Running Loop=1
2019-05-30T16:46:48.087Z,1559234808.087 [MicromodemComms](DEBUG): Aggregate::initialize MicromodemComms
2019-05-30T16:46:48.095Z,1559234808.095 [MicromodemComms:CheckIn] Running Loop=1
2019-05-30T16:46:48.095Z,1559234808.095 [MicromodemComms:CheckIn](DEBUG): Aggregate::initialize MicromodemComms:CheckIn
2019-05-30T16:46:48.095Z,1559234808.095 [MicromodemComms:CheckIn:A] Running Loop=1
2019-05-30T16:46:48.096Z,1559234808.096 [MicromodemComms:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T16:46:48.445Z,1559234808.445 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 0
2019-05-30T16:46:48.722Z,1559234808.722 [MicromodemComms:CheckIn:A] Stopped
2019-05-30T16:46:48.722Z,1559234808.722 [MicromodemComms:CheckIn](INFO): Completed MicromodemComms:CheckIn
2019-05-30T16:46:48.722Z,1559234808.722 [MicromodemComms:CheckIn] Stopped
2019-05-30T16:46:48.722Z,1559234808.722 [MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize MicromodemComms:CheckIn
2019-05-30T16:46:48.722Z,1559234808.722 [MicromodemComms](INFO): Completed MicromodemComms
2019-05-30T16:46:48.723Z,1559234808.723 [MissionManager](INFO): MicromodemComms is completed.
2019-05-30T16:46:48.723Z,1559234808.723 [MissionManager](INFO): Uninitializing Mission MicromodemComms
2019-05-30T16:46:48.723Z,1559234808.723 [MicromodemComms] Stopped
2019-05-30T16:46:48.723Z,1559234808.723 [MicromodemComms](DEBUG): Aggregate::uninitialize MicromodemComms
2019-05-30T16:46:48.888Z,1559234808.888 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T16:46:48.888Z,1559234808.888 [Default] Running Loop=1
2019-05-30T16:46:48.888Z,1559234808.888 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T16:46:48.888Z,1559234808.888 [Default:B.GoToSurface] Running Loop=1
2019-05-30T16:46:48.888Z,1559234808.888 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T16:46:48.889Z,1559234808.889 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T16:46:48.889Z,1559234808.889 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T16:46:48.889Z,1559234808.889 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T16:46:48.890Z,1559234808.890 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T16:46:48.890Z,1559234808.890 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T16:46:48.890Z,1559234808.890 [Default:A.Wait] Running Loop=1
2019-05-30T16:46:48.890Z,1559234808.890 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T16:46:49.303Z,1559234809.303 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-30T16:46:49.303Z,1559234809.303 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T16:46:49.313Z,1559234809.313 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T16:46:49.708Z,1559234809.708 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T16:46:49.708Z,1559234809.708 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-30T16:47:02.212Z,1559234822.212 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T16:47:02.212Z,1559234822.212 [Default:A.Wait] Stopped
2019-05-30T16:47:02.212Z,1559234822.212 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T16:47:02.624Z,1559234822.624 [Default:CheckIn] Running Loop=1
2019-05-30T16:47:02.625Z,1559234822.625 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T16:47:02.625Z,1559234822.625 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T16:47:25.787Z,1559234845.787 [CommandLine](IMPORTANT): got command run ./Missions/Engineering/transit_umodem_2k.xml
2019-05-30T16:47:25.788Z,1559234845.788 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/transit_umodem_2k.xml
2019-05-30T16:47:25.810Z,1559234845.810 [MissionManager](INFO): DefineArg transit_umodem_2km.MicromodemCommsInterval = 2.000000 min
2019-05-30T16:47:25.811Z,1559234845.811 [MissionManager](INFO): Inserting Stack: Missions/Transport/transit.xml
2019-05-30T16:47:25.863Z,1559234845.863 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MissionTimeout = 60.000000 min
2019-05-30T16:47:25.866Z,1559234845.866 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.NeedCommsTime = 30.000000 min
2019-05-30T16:47:25.869Z,1559234845.869 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Latitude = nan arcdeg
2019-05-30T16:47:25.873Z,1559234845.873 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Longitude = nan arcdeg
2019-05-30T16:47:25.876Z,1559234845.876 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Northings = 0.000000 m
2019-05-30T16:47:25.879Z,1559234845.879 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Eastings = 0.000000 m
2019-05-30T16:47:25.882Z,1559234845.882 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Depth = 10.000000 m
2019-05-30T16:47:25.885Z,1559234845.885 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Speed = 1.000000 m/s
2019-05-30T16:47:25.888Z,1559234845.888 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MaxDepth = 20.000000 m
2019-05-30T16:47:25.892Z,1559234845.892 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MinOffshore = 1.000000 km
2019-05-30T16:47:25.896Z,1559234845.896 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MinAltitude = 7.000000 m
2019-05-30T16:47:25.898Z,1559234845.898 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MassHold = 1 bool
2019-05-30T16:47:25.901Z,1559234845.901 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.BuoyancyHold = 1 bool
2019-05-30T16:47:25.902Z,1559234845.902 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-05-30T16:47:26.111Z,1559234846.111 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.DiveInterval = 3.000000 h
2019-05-30T16:47:26.118Z,1559234846.118 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.WaitForPitchUp = 10.000000 min
2019-05-30T16:47:26.125Z,1559234846.125 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-05-30T16:47:26.129Z,1559234846.129 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.SurfaceDepthRate = nan m/s
2019-05-30T16:47:26.140Z,1559234846.140 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-05-30T16:47:26.148Z,1559234846.148 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.GPSTimeout = 7.000000 min
2019-05-30T16:47:26.151Z,1559234846.151 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.CommsTimeout = 30.000000 min
2019-05-30T16:47:26.165Z,1559234846.165 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T16:47:26.205Z,1559234846.205 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-05-30T16:47:26.239Z,1559234846.239 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:StandardEnvelopes.MinAltitude = 5.000000 m
2019-05-30T16:47:26.254Z,1559234846.254 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:StandardEnvelopes.MaxDepth = 200.000000 m
2019-05-30T16:47:26.257Z,1559234846.257 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-05-30T16:47:26.258Z,1559234846.258 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-30T16:47:26.278Z,1559234846.278 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-30T16:47:26.299Z,1559234846.299 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-05-30T16:47:26.316Z,1559234846.316 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2019-05-30T16:47:26.320Z,1559234846.320 [transit_umodem_2km:transit:MassHold.Pitch](DEBUG): Construct.
2019-05-30T16:47:26.356Z,1559234846.356 [transit_umodem_2km:transit:Transit:A.Pitch](DEBUG): Construct.
2019-05-30T16:47:26.362Z,1559234846.362 [transit_umodem_2km:transit:Transit:B.SetSpeed](DEBUG): Construct.
2019-05-30T16:47:26.373Z,1559234846.373 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2019-05-30T16:47:26.390Z,1559234846.390 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.MissionTimeout = value:90.000000 min
2019-05-30T16:47:26.392Z,1559234846.392 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.Latitude = value:36.804900 arcdeg
2019-05-30T16:47:26.395Z,1559234846.395 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.Longitude = value:-121.810800 arcdeg
2019-05-30T16:47:26.405Z,1559234846.405 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.MinOffshore = value:750.000000 m
2019-05-30T16:47:26.406Z,1559234846.406 [MissionManager](INFO): Inserting Stack: Missions/Insert/MicromodemComms.xml
2019-05-30T16:47:26.481Z,1559234846.481 [MissionManager](INFO): DefineArg transit_umodem_2km:MicromodemComms.Timeout = 10.000000 min
2019-05-30T16:47:26.486Z,1559234846.486 [MissionManager](INFO): DefineArg transit_umodem_2km:MicromodemComms.CommsInterval = 5.000000 min
2019-05-30T16:47:26.502Z,1559234846.502 [MissionManager](INFO): RedefineArg transit_umodem_2km:MicromodemComms.CommsInterval = reader:transit_umodem_2km.MicromodemCommsInterval
2019-05-30T16:47:26.529Z,1559234846.529 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="utf-8"?>
<Mission xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
         Id="transit_umodem_2km">

    <Description>
        Vehicle transits to waypoint 2km WNW of Moss Landing, using uModem for comms.
    </Description>

    <DefineArg Name="MicromodemCommsInterval"><Description>
        How often to trigger Umodem communications
    </Description><Units:minute/><Value>2</Value></DefineArg>

    <Insert Filename="Transport/transit.xml">
        <RedefineArg Name="MissionTimeout"><Units:minute/><Value>90</Value></RedefineArg>
        <RedefineArg Name="Latitude"><Units:degree/><Value>36.8049</Value></RedefineArg>
        <RedefineArg Name="Longitude"><Units:degree/><Value>-121.8108</Value></RedefineArg>
        <RedefineArg Name="MinOffshore"><Units:meter/><Value>750</Value></RedefineArg>
    </Insert>

    <Insert Filename="Insert/MicromodemComms.xml" Id="MicromodemComms">
        <RedefineArg Name="CommsInterval"><Arg Name="MicromodemCommsInterval"/></RedefineArg>
    </Insert>

</Mission>


2019-05-30T16:47:26.535Z,1559234846.535 [CommandLine](IMPORTANT): Running ./Missions/Engineering/transit_umodem_2k.xml
2019-05-30T16:47:26.868Z,1559234846.868 [Default] Stopped
2019-05-30T16:47:26.868Z,1559234846.868 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-30T16:47:26.868Z,1559234846.868 [Default:B.GoToSurface] Stopped
2019-05-30T16:47:26.868Z,1559234846.868 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T16:47:26.869Z,1559234846.869 [Default:CheckIn] Stopped
2019-05-30T16:47:26.869Z,1559234846.869 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T16:47:26.869Z,1559234846.869 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T16:47:26.869Z,1559234846.869 [MissionManager](IMPORTANT): Started mission transit_umodem_2km
2019-05-30T16:47:26.869Z,1559234846.869 [transit_umodem_2km] Running Loop=1
2019-05-30T16:47:26.869Z,1559234846.869 [transit_umodem_2km](DEBUG): Aggregate::initialize transit_umodem_2km
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit] Running Loop=1
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit](DEBUG): Aggregate::initialize transit_umodem_2km:transit
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit:StandardEnvelopes] Running Loop=1
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit_umodem_2km:transit:StandardEnvelopes
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-30T16:47:26.870Z,1559234846.870 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-30T16:47:26.871Z,1559234846.871 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-30T16:47:26.871Z,1559234846.871 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-05-30T16:47:26.875Z,1559234846.875 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy] Running Loop=1
2019-05-30T16:47:26.875Z,1559234846.875 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-05-30T16:47:26.875Z,1559234846.875 [transit_umodem_2km:transit:MassHold.Pitch] Running Loop=1
2019-05-30T16:47:26.875Z,1559234846.875 [transit_umodem_2km:transit:MassHold.Pitch](DEBUG): Initialize.
2019-05-30T16:47:26.876Z,1559234846.876 [transit_umodem_2km:transit:B] Running Loop=1
2019-05-30T16:47:26.877Z,1559234846.877 [transit_umodem_2km:transit:MassHold.Pitch] Running Loop=1
2019-05-30T16:47:26.877Z,1559234846.877 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy] Running Loop=1
2019-05-30T16:47:26.878Z,1559234846.878 [transit_umodem_2km:transit:StandardEnvelopes] Running Loop=1
2019-05-30T16:47:26.878Z,1559234846.878 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-30T16:47:26.878Z,1559234846.878 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:26.878Z,1559234846.878 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-30T16:47:26.883Z,1559234846.883 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-30T16:47:26.884Z,1559234846.884 [transit_umodem_2km:transit:B] Stopped
2019-05-30T16:47:26.884Z,1559234846.884 [transit_umodem_2km:transit:C] Running Loop=1
2019-05-30T16:47:26.884Z,1559234846.884 [transit_umodem_2km:transit:NeedComms] Running Loop=1
2019-05-30T16:47:26.884Z,1559234846.884 [transit_umodem_2km:transit:NeedComms](DEBUG): Aggregate::initialize transit_umodem_2km:transit:NeedComms
2019-05-30T16:47:26.884Z,1559234846.884 [transit_umodem_2km:transit:NeedComms:B.GoToSurface] Running Loop=1
2019-05-30T16:47:26.884Z,1559234846.884 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T16:47:26.885Z,1559234846.885 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2019-05-30T16:47:26.885Z,1559234846.885 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2019-05-30T16:47:26.885Z,1559234846.885 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2019-05-30T16:47:26.886Z,1559234846.886 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T16:47:26.886Z,1559234846.886 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T16:47:26.886Z,1559234846.886 [transit_umodem_2km:transit:NeedComms:A] Running Loop=1
2019-05-30T16:47:26.891Z,1559234846.891 [transit_umodem_2km:transit:NeedComms:A](ERROR): data element is not active.
2019-05-30T16:47:26.892Z,1559234846.892 [transit_umodem_2km:transit:NeedComms:A](INFO): last time_fix was: nan second since 1970/01/01T00:00:00Z 
2019-05-30T16:47:26.892Z,1559234846.892 [transit_umodem_2km:transit:NeedComms:A] Stopped
2019-05-30T16:47:27.281Z,1559234847.281 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:27.282Z,1559234847.282 [transit_umodem_2km:transit:C] Stopped
2019-05-30T16:47:27.282Z,1559234847.282 [transit_umodem_2km:transit:E] Running Loop=1
2019-05-30T16:47:27.283Z,1559234847.283 [transit_umodem_2km:transit:NeedComms:C] Running Loop=1
2019-05-30T16:47:27.665Z,1559234847.665 [transit_umodem_2km:transit:E] Stopped
2019-05-30T16:47:27.665Z,1559234847.665 [transit_umodem_2km:transit:F] Running Loop=1
2019-05-30T16:47:27.665Z,1559234847.665 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:27.667Z,1559234847.667 [transit_umodem_2km:transit:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-30T16:47:28.065Z,1559234848.065 [transit_umodem_2km:transit:F] Stopped
2019-05-30T16:47:28.066Z,1559234848.066 [transit_umodem_2km:transit:G] Running Loop=1
2019-05-30T16:47:28.066Z,1559234848.066 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:28.469Z,1559234848.469 [transit_umodem_2km:transit:G] Stopped
2019-05-30T16:47:28.469Z,1559234848.469 [transit_umodem_2km:transit:Transit] Running Loop=1
2019-05-30T16:47:28.469Z,1559234848.469 [transit_umodem_2km:transit:Transit](DEBUG): Aggregate::initialize transit_umodem_2km:transit:Transit
2019-05-30T16:47:28.469Z,1559234848.469 [transit_umodem_2km:transit:Transit:A.Pitch] Running Loop=1
2019-05-30T16:47:28.469Z,1559234848.469 [transit_umodem_2km:transit:Transit:A.Pitch](DEBUG): Initialize.
2019-05-30T16:47:28.470Z,1559234848.470 [transit_umodem_2km:transit:Transit:B.SetSpeed] Running Loop=1
2019-05-30T16:47:28.470Z,1559234848.470 [transit_umodem_2km:transit:Transit:B.SetSpeed](DEBUG): Initialize.
2019-05-30T16:47:28.470Z,1559234848.470 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint] Running Loop=1
2019-05-30T16:47:28.470Z,1559234848.470 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:28.470Z,1559234848.470 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:28.885Z,1559234848.885 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:28.885Z,1559234848.885 [transit_umodem_2km:transit:Transit:B.SetSpeed] Running Loop=1
2019-05-30T16:47:28.885Z,1559234848.885 [transit_umodem_2km:transit:Transit:A.Pitch] Running Loop=1
2019-05-30T16:47:28.886Z,1559234848.886 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:29.334Z,1559234849.334 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:29.380Z,1559234849.380 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:29.698Z,1559234849.698 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:29.700Z,1559234849.700 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:30.188Z,1559234850.188 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:30.189Z,1559234850.189 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:30.488Z,1559234850.488 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:30.490Z,1559234850.490 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:30.901Z,1559234850.901 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:30.902Z,1559234850.902 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:31.314Z,1559234851.314 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:31.316Z,1559234851.316 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:31.713Z,1559234851.713 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:31.714Z,1559234851.714 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:32.105Z,1559234852.105 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:32.106Z,1559234852.106 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:32.507Z,1559234852.507 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:32.509Z,1559234852.509 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:32.913Z,1559234852.913 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:32.914Z,1559234852.914 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:33.333Z,1559234853.333 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:33.334Z,1559234853.334 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:33.725Z,1559234853.725 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:33.726Z,1559234853.726 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:34.157Z,1559234854.157 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:34.164Z,1559234854.164 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:34.549Z,1559234854.549 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:34.550Z,1559234854.550 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:34.956Z,1559234854.956 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:34.958Z,1559234854.958 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:35.353Z,1559234855.353 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:35.371Z,1559234855.371 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:35.737Z,1559234855.737 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:35.738Z,1559234855.738 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:36.157Z,1559234856.157 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:36.158Z,1559234856.158 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:36.549Z,1559234856.549 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:36.550Z,1559234856.550 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:36.961Z,1559234856.961 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:36.962Z,1559234856.962 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:37.372Z,1559234857.372 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:37.374Z,1559234857.374 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:37.770Z,1559234857.770 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:37.772Z,1559234857.772 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:38.192Z,1559234858.192 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:38.194Z,1559234858.194 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:38.632Z,1559234858.632 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:38.634Z,1559234858.634 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:39.115Z,1559234859.115 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:39.117Z,1559234859.117 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:39.413Z,1559234859.413 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:39.414Z,1559234859.414 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:39.805Z,1559234859.805 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:39.806Z,1559234859.806 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:40.197Z,1559234860.197 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:40.199Z,1559234860.199 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:40.598Z,1559234860.598 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:40.600Z,1559234860.600 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:41.024Z,1559234861.024 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:41.032Z,1559234861.032 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:41.427Z,1559234861.427 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:41.429Z,1559234861.429 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:41.813Z,1559234861.813 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:41.814Z,1559234861.814 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:42.218Z,1559234862.218 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:42.220Z,1559234862.220 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:42.621Z,1559234862.621 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:42.622Z,1559234862.622 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:43.042Z,1559234863.042 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:43.044Z,1559234863.044 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:43.421Z,1559234863.421 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:43.422Z,1559234863.422 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:43.824Z,1559234863.824 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:43.825Z,1559234863.825 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:44.241Z,1559234864.241 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:44.243Z,1559234864.243 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:44.629Z,1559234864.629 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:44.630Z,1559234864.630 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:45.069Z,1559234865.069 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:45.075Z,1559234865.075 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:45.433Z,1559234865.433 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:45.434Z,1559234865.434 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:45.841Z,1559234865.841 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:45.842Z,1559234865.842 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:46.248Z,1559234866.248 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:46.250Z,1559234866.250 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:46.660Z,1559234866.660 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:46.662Z,1559234866.662 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:47.075Z,1559234867.075 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:47.077Z,1559234867.077 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:47.477Z,1559234867.477 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:47.478Z,1559234867.478 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:47.885Z,1559234867.885 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:47.886Z,1559234867.886 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:48.265Z,1559234868.265 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:48.266Z,1559234868.266 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:48.669Z,1559234868.669 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:48.670Z,1559234868.670 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:49.077Z,1559234869.077 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:49.079Z,1559234869.079 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:49.477Z,1559234869.477 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:49.479Z,1559234869.479 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:49.885Z,1559234869.885 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:49.886Z,1559234869.886 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:50.309Z,1559234870.309 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:50.311Z,1559234870.311 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:50.705Z,1559234870.705 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:50.707Z,1559234870.707 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:51.097Z,1559234871.097 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:51.111Z,1559234871.111 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:51.255Z,1559234871.255 [CommandLine](IMPORTANT): got command stop
2019-05-30T16:47:51.256Z,1559234871.256 [CommandLine](IMPORTANT): Scheduling is paused
2019-05-30T16:47:51.256Z,1559234871.256 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-05-30T16:47:51.509Z,1559234871.509 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-30T16:47:51.510Z,1559234871.510 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-30T16:47:51.512Z,1559234871.512 [MissionManager](INFO): MissionManager is completed.
2019-05-30T16:47:51.512Z,1559234871.512 [MissionManager](INFO): Uninitializing Mission transit_umodem_2km
2019-05-30T16:47:51.512Z,1559234871.512 [transit_umodem_2km] Stopped
2019-05-30T16:47:51.512Z,1559234871.512 [transit_umodem_2km](DEBUG): Aggregate::uninitialize transit_umodem_2km
2019-05-30T16:47:51.512Z,1559234871.512 [transit_umodem_2km:transit] Stopped
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:NeedComms] Stopped
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:NeedComms](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit:NeedComms
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:NeedComms:B.GoToSurface] Stopped
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:NeedComms:C] Stopped
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:StandardEnvelopes] Stopped
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit:StandardEnvelopes
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-05-30T16:47:51.513Z,1559234871.513 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy] Stopped
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:MassHold.Pitch] Stopped
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:Transit] Stopped
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:Transit](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit:Transit
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:Transit:A.Pitch] Stopped
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:Transit:B.SetSpeed] Stopped
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:Transit:B.SetSpeed](DEBUG): Uninitialize.
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint] Stopped
2019-05-30T16:47:51.514Z,1559234871.514 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2019-05-30T16:47:52.010Z,1559234872.010 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T16:47:52.010Z,1559234872.010 [Default] Running Loop=1
2019-05-30T16:47:52.011Z,1559234872.011 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T16:47:52.011Z,1559234872.011 [Default:B.GoToSurface] Running Loop=1
2019-05-30T16:47:52.012Z,1559234872.012 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T16:47:52.012Z,1559234872.012 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T16:47:52.013Z,1559234872.013 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T16:47:52.014Z,1559234872.014 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T16:47:52.015Z,1559234872.015 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T16:47:52.017Z,1559234872.017 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T16:47:52.018Z,1559234872.018 [Default:A.Wait] Running Loop=1
2019-05-30T16:47:52.018Z,1559234872.018 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T16:47:57.851Z,1559234877.851 [CommandLine](IMPORTANT): got command get latitude
2019-05-30T16:47:57.852Z,1559234877.852 [CommandLine](FAULT): Element has no value
2019-05-30T16:48:05.237Z,1559234885.237 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T16:48:05.238Z,1559234885.238 [Default:A.Wait] Stopped
2019-05-30T16:48:05.238Z,1559234885.238 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T16:48:05.699Z,1559234885.699 [Default:CheckIn] Running Loop=1
2019-05-30T16:48:05.700Z,1559234885.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T16:48:05.700Z,1559234885.700 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T16:48:12.772Z,1559234892.772 [CommandLine](IMPORTANT): got command set latitude 80.000000 degree
2019-05-30T16:49:03.415Z,1559234943.415 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T16:49:03.415Z,1559234943.415 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053009582765,35.0, -0.1,   0.0,10
2019-05-30T16:49:23.987Z,1559234963.987 [NAL9602](INFO): SBD MO Status=0, MOMSN=5584, MT Status=0, MTMSN=0
2019-05-30T16:49:23.988Z,1559234963.988 [NAL9602](INFO): No messages in MT queue
2019-05-30T16:49:24.803Z,1559234964.803 [NAL9602](DEBUG): Fix Requested
2019-05-30T16:49:25.195Z,1559234965.195 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164918.00,A,3648.17078,N,12147.27955,W,0.194,258.23,300519,,,A*7E
2019-05-30T16:49:25.209Z,1559234965.209 [NAL9602](INFO): GPS fix at 20190530T164918: (36.802846, -121.787993)
2019-05-30T16:49:25.242Z,1559234965.242 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T16:49:25.243Z,1559234965.243 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T16:49:25.677Z,1559234965.677 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T16:49:26.046Z,1559234966.046 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 0
2019-05-30T16:49:26.320Z,1559234966.320 [Micromodem](INFO): Outgoing frame #1: 3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567
2019-05-30T16:49:26.321Z,1559234966.321 [Micromodem](INFO): Outgoing frame #2: 266CC0E6F1A517638CB0C0B8BE35994FEABFBDB92FCD92215011E57437C4F5E5F0EC9E14B85A146956ECB75E9F5714D7DBF47C37AF9BB003AE5DC2F70FE304F6
2019-05-30T16:49:26.321Z,1559234966.321 [Micromodem](INFO): Outgoing frame #3: B3E74F2048B14D68F5DE6A13DF4FA06075CAA87D1CF047737B5CBD634C385F34DE5D20CA7A5F635220D90674665503574914BE7D204248BB7433BBCABA528AA7
2019-05-30T16:49:26.321Z,1559234966.321 [Micromodem](DEBUG): Nmea buf: $CCCYC,0,1,10,1,0,3*6B

2019-05-30T16:49:26.321Z,1559234966.321 [Micromodem](INFO): Nmea out: $CCCYC,0,1,10,1,0,3*6B

2019-05-30T16:49:26.460Z,1559234966.460 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:26.460Z,1559234966.460 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:26.832Z,1559234966.832 [Micromodem](INFO): Nmea in: $CACYC,0,1,10,1,0,3*69

2019-05-30T16:49:26.833Z,1559234966.833 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:26.833Z,1559234966.833 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:27.233Z,1559234967.233 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:27.233Z,1559234967.233 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:27.643Z,1559234967.643 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:27.643Z,1559234967.643 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:28.047Z,1559234968.047 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:28.051Z,1559234968.051 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:28.441Z,1559234968.441 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:28.441Z,1559234968.441 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:28.849Z,1559234968.849 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:28.849Z,1559234968.849 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:29.252Z,1559234969.252 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:29.253Z,1559234969.253 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:29.653Z,1559234969.653 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:29.653Z,1559234969.653 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:30.057Z,1559234970.057 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:30.057Z,1559234970.057 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:30.460Z,1559234970.460 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:30.461Z,1559234970.461 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:30.865Z,1559234970.865 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:30.865Z,1559234970.865 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:31.269Z,1559234971.269 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:31.269Z,1559234971.269 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:31.673Z,1559234971.673 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:31.673Z,1559234971.673 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:32.077Z,1559234972.077 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:32.077Z,1559234972.077 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:32.481Z,1559234972.481 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:32.481Z,1559234972.481 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:32.885Z,1559234972.885 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:32.885Z,1559234972.885 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:33.289Z,1559234973.289 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:33.289Z,1559234973.289 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:33.701Z,1559234973.701 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:33.701Z,1559234973.701 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:34.097Z,1559234974.097 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:34.097Z,1559234974.097 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:34.501Z,1559234974.501 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:34.501Z,1559234974.501 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:34.909Z,1559234974.909 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:34.909Z,1559234974.909 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:35.312Z,1559234975.312 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:35.313Z,1559234975.313 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:35.713Z,1559234975.713 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:35.713Z,1559234975.713 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:36.117Z,1559234976.117 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:36.117Z,1559234976.117 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:36.521Z,1559234976.521 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:36.521Z,1559234976.521 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:36.929Z,1559234976.929 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:36.929Z,1559234976.929 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:37.351Z,1559234977.351 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:37.351Z,1559234977.351 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:37.733Z,1559234977.733 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:37.733Z,1559234977.733 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:38.149Z,1559234978.149 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:38.149Z,1559234978.149 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:38.544Z,1559234978.544 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:38.544Z,1559234978.544 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:38.949Z,1559234978.949 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:38.949Z,1559234978.949 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:39.353Z,1559234979.353 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:39.353Z,1559234979.353 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:39.765Z,1559234979.765 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:39.765Z,1559234979.765 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:40.169Z,1559234980.169 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:40.169Z,1559234980.169 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:40.561Z,1559234980.561 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:40.561Z,1559234980.561 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:40.972Z,1559234980.972 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:40.972Z,1559234980.972 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:41.373Z,1559234981.373 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:41.373Z,1559234981.373 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:41.777Z,1559234981.777 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:41.777Z,1559234981.777 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:42.177Z,1559234982.177 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:42.177Z,1559234982.177 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:42.581Z,1559234982.581 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:42.581Z,1559234982.581 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:42.993Z,1559234982.993 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:42.994Z,1559234982.994 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:43.397Z,1559234983.397 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:43.397Z,1559234983.397 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:43.793Z,1559234983.793 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:43.793Z,1559234983.793 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:44.197Z,1559234984.197 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:44.197Z,1559234984.197 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:44.605Z,1559234984.605 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:44.605Z,1559234984.605 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:45.029Z,1559234985.029 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:45.029Z,1559234985.029 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:45.413Z,1559234985.413 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:45.413Z,1559234985.413 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:45.814Z,1559234985.814 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:45.814Z,1559234985.814 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:46.221Z,1559234986.221 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:46.221Z,1559234986.221 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:46.621Z,1559234986.621 [Micromodem](INFO): Nmea in: $CADRQ,164927,1,10,0,64,1*79

2019-05-30T16:49:46.622Z,1559234986.622 [Micromodem](DEBUG): Nmea buf: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:49:46.622Z,1559234986.622 [Micromodem](INFO): Nmea out: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:49:46.626Z,1559234986.626 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:46.628Z,1559234986.628 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:47.035Z,1559234987.035 [Micromodem](INFO): Nmea in: $CAERR,164947,DATA_TIMEOUT,1*47

2019-05-30T16:49:47.036Z,1559234987.036 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,164947,DATA_TIMEOUT,1*47

2019-05-30T16:49:47.036Z,1559234987.036 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:47.036Z,1559234987.036 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:47.433Z,1559234987.433 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:47.433Z,1559234987.433 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:47.838Z,1559234987.838 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:47.838Z,1559234987.838 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:48.241Z,1559234988.241 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:48.241Z,1559234988.241 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:48.641Z,1559234988.641 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:48.641Z,1559234988.641 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:49.049Z,1559234989.049 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:49.049Z,1559234989.049 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:49.457Z,1559234989.457 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:49.457Z,1559234989.457 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:49.856Z,1559234989.856 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:49.857Z,1559234989.857 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:50.257Z,1559234990.257 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:50.257Z,1559234990.257 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:50.665Z,1559234990.665 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:50.665Z,1559234990.665 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:51.065Z,1559234991.065 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:51.065Z,1559234991.065 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:51.473Z,1559234991.473 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:51.474Z,1559234991.474 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:51.873Z,1559234991.873 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:51.873Z,1559234991.873 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:52.277Z,1559234992.277 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:52.277Z,1559234992.277 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:52.685Z,1559234992.685 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:52.685Z,1559234992.685 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:53.085Z,1559234993.085 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:53.085Z,1559234993.085 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:53.486Z,1559234993.486 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:53.486Z,1559234993.486 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:53.897Z,1559234993.897 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:53.897Z,1559234993.897 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:54.301Z,1559234994.301 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:54.301Z,1559234994.301 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:54.704Z,1559234994.704 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:54.705Z,1559234994.705 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:55.109Z,1559234995.109 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:55.109Z,1559234995.109 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:55.517Z,1559234995.517 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:55.517Z,1559234995.517 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:55.916Z,1559234995.916 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:55.917Z,1559234995.917 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:56.321Z,1559234996.321 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:56.321Z,1559234996.321 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:56.726Z,1559234996.726 [Micromodem](INFO): Nmea in: $CAERR,164947,NI  ,17,Argument value out of range*0F

2019-05-30T16:49:56.726Z,1559234996.726 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,164947,NI  ,17,Argument value out of range*0F

2019-05-30T16:49:56.726Z,1559234996.726 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:56.726Z,1559234996.726 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:57.125Z,1559234997.125 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:57.125Z,1559234997.125 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:57.533Z,1559234997.533 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:57.533Z,1559234997.533 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:57.533Z,1559234997.533 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T16:49:57.936Z,1559234997.936 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:49:57.938Z,1559234997.938 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:57.938Z,1559234997.938 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:58.337Z,1559234998.337 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:58.338Z,1559234998.338 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:58.749Z,1559234998.749 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:58.749Z,1559234998.749 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:59.149Z,1559234999.149 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:59.149Z,1559234999.149 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:59.546Z,1559234999.546 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:59.546Z,1559234999.546 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:49:59.957Z,1559234999.957 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:49:59.957Z,1559234999.957 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:00.361Z,1559235000.361 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:00.361Z,1559235000.361 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:00.761Z,1559235000.761 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:00.761Z,1559235000.761 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:01.169Z,1559235001.169 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:01.169Z,1559235001.169 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:01.573Z,1559235001.573 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:01.573Z,1559235001.573 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:01.982Z,1559235001.982 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:01.982Z,1559235001.982 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:02.377Z,1559235002.377 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:02.377Z,1559235002.377 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:02.785Z,1559235002.785 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:02.785Z,1559235002.785 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:03.188Z,1559235003.188 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:03.189Z,1559235003.189 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:03.593Z,1559235003.593 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:03.593Z,1559235003.593 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:04.005Z,1559235004.005 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:04.005Z,1559235004.005 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:04.034Z,1559235004.034 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-05-30T16:50:04.034Z,1559235004.034 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,       -0.55,       -3.  -0.05,   9.56,  0.00
2019-05-30T16:50:04.399Z,1559235004.399 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:04.399Z,1559235004.399 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:04.833Z,1559235004.833 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:04.833Z,1559235004.833 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:05.206Z,1559235005.206 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:05.206Z,1559235005.206 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:05.609Z,1559235005.609 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:05.609Z,1559235005.609 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:06.041Z,1559235006.041 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:06.041Z,1559235006.041 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:06.422Z,1559235006.422 [Micromodem](INFO): Nmea in: $CAERR,164959,NI  ,17,Argument value out of range*00

2019-05-30T16:50:06.422Z,1559235006.422 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,164959,NI  ,17,Argument value out of range*00

2019-05-30T16:50:06.422Z,1559235006.422 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:06.422Z,1559235006.422 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:06.825Z,1559235006.825 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:06.825Z,1559235006.825 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:07.225Z,1559235007.225 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:07.226Z,1559235007.226 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:07.626Z,1559235007.626 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:07.627Z,1559235007.627 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:08.044Z,1559235008.044 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:08.045Z,1559235008.045 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:08.438Z,1559235008.438 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:08.438Z,1559235008.438 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:08.852Z,1559235008.852 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:08.853Z,1559235008.853 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:09.249Z,1559235009.249 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:50:09.250Z,1559235009.250 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:09.251Z,1559235009.251 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:09.662Z,1559235009.662 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:09.662Z,1559235009.662 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:10.057Z,1559235010.057 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:10.057Z,1559235010.057 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:10.460Z,1559235010.460 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:10.461Z,1559235010.461 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:10.865Z,1559235010.865 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:10.865Z,1559235010.865 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:11.269Z,1559235011.269 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:11.269Z,1559235011.269 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:11.672Z,1559235011.672 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:11.673Z,1559235011.673 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:12.081Z,1559235012.081 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:12.081Z,1559235012.081 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:12.492Z,1559235012.492 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:12.492Z,1559235012.492 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:12.899Z,1559235012.899 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:12.899Z,1559235012.899 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:13.289Z,1559235013.289 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:13.289Z,1559235013.289 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:13.705Z,1559235013.705 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:13.705Z,1559235013.705 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:14.097Z,1559235014.097 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:14.097Z,1559235014.097 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:14.499Z,1559235014.499 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:14.499Z,1559235014.499 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:14.904Z,1559235014.904 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:14.904Z,1559235014.904 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:15.312Z,1559235015.312 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:15.313Z,1559235015.313 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:15.721Z,1559235015.721 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:15.721Z,1559235015.721 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:16.117Z,1559235016.117 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:16.117Z,1559235016.117 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:16.522Z,1559235016.522 [Micromodem](INFO): Nmea in: $CAERR,165010,NI  ,17,Argument value out of range*05

2019-05-30T16:50:16.522Z,1559235016.522 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,165010,NI  ,17,Argument value out of range*05

2019-05-30T16:50:16.522Z,1559235016.522 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:16.522Z,1559235016.522 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:16.926Z,1559235016.926 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:16.926Z,1559235016.926 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:17.329Z,1559235017.329 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:17.329Z,1559235017.329 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:17.729Z,1559235017.729 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:17.729Z,1559235017.729 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:18.137Z,1559235018.137 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:18.137Z,1559235018.137 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:18.538Z,1559235018.538 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:18.538Z,1559235018.538 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:18.944Z,1559235018.944 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:18.945Z,1559235018.945 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:19.345Z,1559235019.345 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:19.345Z,1559235019.345 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:19.753Z,1559235019.753 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:19.753Z,1559235019.753 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:20.156Z,1559235020.156 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:20.157Z,1559235020.157 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:20.557Z,1559235020.557 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:50:20.561Z,1559235020.561 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:20.562Z,1559235020.562 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:20.966Z,1559235020.966 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:20.966Z,1559235020.966 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:21.368Z,1559235021.368 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:21.369Z,1559235021.369 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:21.773Z,1559235021.773 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:21.773Z,1559235021.773 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:22.173Z,1559235022.173 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:22.173Z,1559235022.173 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:22.615Z,1559235022.615 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:22.615Z,1559235022.615 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:22.997Z,1559235022.997 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:22.997Z,1559235022.997 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:23.393Z,1559235023.393 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:23.393Z,1559235023.393 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:23.797Z,1559235023.797 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:23.797Z,1559235023.797 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:24.201Z,1559235024.201 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:24.202Z,1559235024.202 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:24.621Z,1559235024.621 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:24.621Z,1559235024.621 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:25.048Z,1559235025.048 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:25.048Z,1559235025.048 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:25.413Z,1559235025.413 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:25.413Z,1559235025.413 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:25.821Z,1559235025.821 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:25.821Z,1559235025.821 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:26.225Z,1559235026.225 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:26.225Z,1559235026.225 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:26.627Z,1559235026.627 [Micromodem](INFO): Nmea in: $CAERR,165021,NI  ,17,Argument value out of range*07

2019-05-30T16:50:26.628Z,1559235026.628 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,165021,NI  ,17,Argument value out of range*07

2019-05-30T16:50:26.628Z,1559235026.628 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:26.629Z,1559235026.629 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:27.060Z,1559235027.060 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:27.060Z,1559235027.060 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:27.443Z,1559235027.443 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:27.443Z,1559235027.443 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:27.848Z,1559235027.848 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:27.848Z,1559235027.848 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:28.241Z,1559235028.241 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:28.241Z,1559235028.241 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:28.657Z,1559235028.657 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:28.657Z,1559235028.657 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:29.057Z,1559235029.057 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:29.057Z,1559235029.057 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:29.453Z,1559235029.453 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:29.453Z,1559235029.453 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:29.868Z,1559235029.868 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:29.868Z,1559235029.868 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:30.001Z,1559235030.001 [CommandLine](IMPORTANT): got command get latitude
2019-05-30T16:50:30.003Z,1559235030.003 [CommandLine](IMPORTANT): latitude 36.802857 arcdeg
2019-05-30T16:50:30.261Z,1559235030.261 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:30.261Z,1559235030.261 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:30.665Z,1559235030.665 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:30.665Z,1559235030.665 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:31.072Z,1559235031.072 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:31.073Z,1559235031.073 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:31.477Z,1559235031.477 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:31.477Z,1559235031.477 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:31.477Z,1559235031.477 [Micromodem](ERROR): Buffer fill timout failure.
2019-05-30T16:50:31.880Z,1559235031.880 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:50:31.882Z,1559235031.882 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 0
2019-05-30T16:50:32.256Z,1559235032.256 [Micromodem](INFO): Outgoing frame #1: 3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567
2019-05-30T16:50:32.257Z,1559235032.257 [Micromodem](INFO): Outgoing frame #2: 266CC0E6F1A517638CB0C0B8BE35994FEABFBDB92FCD92215011E57437C4F5E5F0EC9E14B85A146956ECB75E9F5714D7DBF47C37AF9BB003AE5DC2F70FE304F6
2019-05-30T16:50:32.257Z,1559235032.257 [Micromodem](INFO): Outgoing frame #3: B3E74F2048B14D68F5DE6A13DF4FA06075CAA87D1CF047737B5CBD634C385F34DE5D20CA7A5F635220D90674665503574914BE7D204248BB7433BBCABA528AA7
2019-05-30T16:50:32.257Z,1559235032.257 [Micromodem](DEBUG): Nmea buf: $CCCYC,0,1,10,1,0,3*6B

2019-05-30T16:50:32.386Z,1559235032.386 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:32.386Z,1559235032.386 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:32.725Z,1559235032.725 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:32.725Z,1559235032.725 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:33.128Z,1559235033.128 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:33.129Z,1559235033.129 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:33.533Z,1559235033.533 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:33.533Z,1559235033.533 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:33.933Z,1559235033.933 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:33.933Z,1559235033.933 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:34.344Z,1559235034.344 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:34.345Z,1559235034.345 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:34.741Z,1559235034.741 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:34.741Z,1559235034.741 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:35.149Z,1559235035.149 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:35.149Z,1559235035.149 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:35.553Z,1559235035.553 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:35.553Z,1559235035.553 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:35.957Z,1559235035.957 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:35.957Z,1559235035.957 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:36.361Z,1559235036.361 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:36.361Z,1559235036.361 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:36.766Z,1559235036.766 [Micromodem](INFO): Nmea in: $CAERR,165033,NI  ,17,Argument value out of range*04

2019-05-30T16:50:36.766Z,1559235036.766 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,165033,NI  ,17,Argument value out of range*04

2019-05-30T16:50:36.766Z,1559235036.766 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:36.766Z,1559235036.766 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:37.166Z,1559235037.166 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:37.166Z,1559235037.166 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:37.569Z,1559235037.569 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:37.569Z,1559235037.569 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:37.974Z,1559235037.974 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:37.974Z,1559235037.974 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:38.381Z,1559235038.381 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:38.381Z,1559235038.381 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:38.781Z,1559235038.781 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:38.781Z,1559235038.781 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:39.188Z,1559235039.188 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:39.189Z,1559235039.189 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:39.589Z,1559235039.589 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:39.589Z,1559235039.589 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:40.008Z,1559235040.008 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:40.008Z,1559235040.008 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:40.404Z,1559235040.404 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:40.404Z,1559235040.404 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:40.801Z,1559235040.801 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:40.801Z,1559235040.801 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:41.205Z,1559235041.205 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:41.205Z,1559235041.205 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:41.612Z,1559235041.612 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:41.613Z,1559235041.613 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:42.033Z,1559235042.033 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:42.033Z,1559235042.033 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:42.417Z,1559235042.417 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:42.417Z,1559235042.417 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:42.824Z,1559235042.824 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:42.825Z,1559235042.825 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:43.228Z,1559235043.228 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:50:43.233Z,1559235043.233 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:43.233Z,1559235043.233 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:43.633Z,1559235043.633 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:43.634Z,1559235043.634 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:44.037Z,1559235044.037 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:44.037Z,1559235044.037 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:44.441Z,1559235044.441 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:44.441Z,1559235044.441 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:44.857Z,1559235044.857 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:44.857Z,1559235044.857 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:45.249Z,1559235045.249 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:45.250Z,1559235045.250 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:45.665Z,1559235045.665 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:45.665Z,1559235045.665 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:46.061Z,1559235046.061 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:46.061Z,1559235046.061 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:46.464Z,1559235046.464 [Micromodem](INFO): Nmea in: $CAERR,165044,NI  ,17,Argument value out of range*04

2019-05-30T16:50:46.464Z,1559235046.464 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,165044,NI  ,17,Argument value out of range*04

2019-05-30T16:50:46.465Z,1559235046.465 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:46.465Z,1559235046.465 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:46.870Z,1559235046.870 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:46.870Z,1559235046.870 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:47.269Z,1559235047.269 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:47.269Z,1559235047.269 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:47.672Z,1559235047.672 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:47.673Z,1559235047.673 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:48.073Z,1559235048.073 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:48.073Z,1559235048.073 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:48.477Z,1559235048.477 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:48.477Z,1559235048.477 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:48.884Z,1559235048.884 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:48.885Z,1559235048.885 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:49.285Z,1559235049.285 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:49.285Z,1559235049.285 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:49.695Z,1559235049.695 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:49.695Z,1559235049.695 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:50.059Z,1559235050.059 [CommandLine](IMPORTANT): got command stop
2019-05-30T16:50:50.096Z,1559235050.096 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:50.097Z,1559235050.097 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:50.501Z,1559235050.501 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:50.501Z,1559235050.501 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:50.905Z,1559235050.905 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:50.905Z,1559235050.905 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:51.305Z,1559235051.305 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:51.305Z,1559235051.305 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:51.709Z,1559235051.709 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:51.710Z,1559235051.710 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:52.117Z,1559235052.117 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:52.117Z,1559235052.117 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:52.520Z,1559235052.520 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:52.521Z,1559235052.521 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:52.925Z,1559235052.925 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:52.925Z,1559235052.925 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:53.325Z,1559235053.325 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:53.325Z,1559235053.325 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:53.732Z,1559235053.732 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:53.733Z,1559235053.733 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:54.131Z,1559235054.131 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:54.131Z,1559235054.131 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:54.540Z,1559235054.540 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:50:54.542Z,1559235054.542 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:54.542Z,1559235054.542 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:54.945Z,1559235054.945 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:54.945Z,1559235054.945 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:55.345Z,1559235055.345 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:55.345Z,1559235055.345 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:55.749Z,1559235055.749 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:55.749Z,1559235055.749 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:56.160Z,1559235056.160 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:56.161Z,1559235056.161 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:56.562Z,1559235056.562 [Micromodem](INFO): Nmea in: $CAERR,165055,NI  ,17,Argument value out of range*04

2019-05-30T16:50:56.562Z,1559235056.562 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,165055,NI  ,17,Argument value out of range*04

2019-05-30T16:50:56.563Z,1559235056.563 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:56.579Z,1559235056.579 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:56.966Z,1559235056.966 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:56.966Z,1559235056.966 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:57.369Z,1559235057.369 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:57.369Z,1559235057.369 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:57.773Z,1559235057.773 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:57.773Z,1559235057.773 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:58.173Z,1559235058.173 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:58.173Z,1559235058.173 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:58.581Z,1559235058.581 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:58.581Z,1559235058.581 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:58.993Z,1559235058.993 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:58.994Z,1559235058.994 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:59.391Z,1559235059.391 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:59.391Z,1559235059.391 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:50:59.789Z,1559235059.789 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:50:59.789Z,1559235059.789 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:00.071Z,1559235060.071 [CommandLine](IMPORTANT): got command stop
2019-05-30T16:51:00.197Z,1559235060.197 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:00.197Z,1559235060.197 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:00.597Z,1559235060.597 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:00.597Z,1559235060.597 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:01.028Z,1559235061.028 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:01.028Z,1559235061.028 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:01.409Z,1559235061.409 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:01.409Z,1559235061.409 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:01.809Z,1559235061.809 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:01.809Z,1559235061.809 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:02.216Z,1559235062.216 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:02.217Z,1559235062.217 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:02.621Z,1559235062.621 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:02.621Z,1559235062.621 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:03.041Z,1559235063.041 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:03.041Z,1559235063.041 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:03.429Z,1559235063.429 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:03.429Z,1559235063.429 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:03.833Z,1559235063.833 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:03.833Z,1559235063.833 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:04.237Z,1559235064.237 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:04.237Z,1559235064.237 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:04.637Z,1559235064.637 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:04.637Z,1559235064.637 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:05.045Z,1559235065.045 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:05.045Z,1559235065.045 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:05.449Z,1559235065.449 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:05.449Z,1559235065.449 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:05.856Z,1559235065.856 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:51:05.858Z,1559235065.858 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:05.858Z,1559235065.858 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:06.254Z,1559235066.254 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:06.254Z,1559235066.254 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:06.658Z,1559235066.658 [Micromodem](INFO): Nmea in: $CAERR,165107,NI  ,17,Argument value out of range*02

2019-05-30T16:51:06.658Z,1559235066.658 [Micromodem](ERROR): TXD response from modem unexpected: $CAERR,165107,NI  ,17,Argument value out of range*02

2019-05-30T16:51:06.658Z,1559235066.658 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:06.659Z,1559235066.659 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:07.065Z,1559235067.065 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:07.065Z,1559235067.065 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:07.465Z,1559235067.465 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:07.465Z,1559235067.465 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:07.869Z,1559235067.869 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:07.869Z,1559235067.869 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:08.273Z,1559235068.273 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:08.273Z,1559235068.273 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:08.677Z,1559235068.677 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:08.677Z,1559235068.677 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:09.079Z,1559235069.079 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:09.079Z,1559235069.079 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:09.493Z,1559235069.493 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:09.493Z,1559235069.493 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:09.889Z,1559235069.889 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:09.889Z,1559235069.889 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:10.293Z,1559235070.293 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:10.293Z,1559235070.293 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:10.700Z,1559235070.700 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:10.701Z,1559235070.701 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:11.105Z,1559235071.105 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:11.105Z,1559235071.105 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:11.505Z,1559235071.505 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:11.505Z,1559235071.505 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:11.912Z,1559235071.912 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:11.913Z,1559235071.913 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:12.322Z,1559235072.322 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:12.322Z,1559235072.322 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:12.717Z,1559235072.717 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:12.717Z,1559235072.717 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:13.124Z,1559235073.124 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:13.125Z,1559235073.125 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:13.529Z,1559235073.529 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:13.529Z,1559235073.529 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:13.929Z,1559235073.929 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:13.929Z,1559235073.929 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:13.956Z,1559235073.956 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-05-30T16:51:13.987Z,1559235073.987 [BPC1](INFO): Received data from all battery sticks.
2019-05-30T16:51:14.333Z,1559235074.333 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:14.333Z,1559235074.333 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:14.737Z,1559235074.737 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:14.737Z,1559235074.737 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:15.141Z,1559235075.141 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:15.141Z,1559235075.141 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:15.545Z,1559235075.545 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:15.545Z,1559235075.545 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:15.962Z,1559235075.962 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:15.962Z,1559235075.962 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:16.353Z,1559235076.353 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:16.353Z,1559235076.353 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:16.761Z,1559235076.761 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:16.762Z,1559235076.762 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:17.165Z,1559235077.165 [Micromodem](ERROR): Nmea resend: $CCTXD,1,10,1,3B08F05C070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4B

2019-05-30T16:51:17.169Z,1559235077.169 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:17.170Z,1559235077.170 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:17.229Z,1559235077.229 [CommandLine](IMPORTANT): got command quit
2019-05-30T16:51:17.581Z,1559235077.581 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:17.581Z,1559235077.581 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:17.970Z,1559235077.970 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:17.970Z,1559235077.970 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:18.235Z,1559235078.235 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:51:18.235Z,1559235078.235 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.291Z,1559235078.291 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-30T16:51:18.291Z,1559235078.291 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.292Z,1559235078.292 [CommandLine](INFO): Join timeout helper Thread ID is 734
2019-05-30T16:51:18.292Z,1559235078.292 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-30T16:51:18.292Z,1559235078.292 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.293Z,1559235078.293 [NavChartDb](INFO): Join timeout helper Thread ID is 735
2019-05-30T16:51:18.373Z,1559235078.373 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:18.373Z,1559235078.373 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:18.391Z,1559235078.391 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:51:18.392Z,1559235078.392 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.392Z,1559235078.392 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-05-30T16:51:18.392Z,1559235078.392 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.393Z,1559235078.393 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 736
2019-05-30T16:51:18.651Z,1559235078.651 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:51:18.651Z,1559235078.651 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T16:51:18.652Z,1559235078.652 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.659Z,1559235078.659 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-30T16:51:18.659Z,1559235078.659 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.659Z,1559235078.659 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 737
2019-05-30T16:51:18.671Z,1559235078.671 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:51:18.672Z,1559235078.672 [CTD_NeilBrown](INFO): Powering down
2019-05-30T16:51:18.683Z,1559235078.683 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.699Z,1559235078.699 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-30T16:51:18.699Z,1559235078.699 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:18.699Z,1559235078.699 [Radio_Surface](INFO): Join timeout helper Thread ID is 738
2019-05-30T16:51:18.781Z,1559235078.781 [Micromodem](INFO): **** isDataRequested  IN Runnable ****, commsState_= 1
2019-05-30T16:51:18.781Z,1559235078.781 [Micromodem](INFO): ************** SENDING_TRANSMIT **************

2019-05-30T16:51:19.040Z,1559235079.040 [Radio_Surface](INFO): Powering down
2019-05-30T16:51:19.042Z,1559235079.042 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:51:19.043Z,1559235079.043 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.062Z,1559235079.062 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-30T16:51:19.062Z,1559235079.062 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.063Z,1559235079.063 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:51:19.064Z,1559235079.064 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.064Z,1559235079.064 [logger](INFO): Join timeout helper Thread ID is 739
2019-05-30T16:51:19.084Z,1559235079.084 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-30T16:51:19.084Z,1559235079.084 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.084Z,1559235079.084 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-30T16:51:19.084Z,1559235079.084 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.084Z,1559235079.084 [controlThread](INFO): Join timeout helper Thread ID is 740
2019-05-30T16:51:19.163Z,1559235079.163 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:51:19.164Z,1559235079.164 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-30T16:51:19.164Z,1559235079.164 [AHRS_M2](INFO): Powering down
2019-05-30T16:51:19.236Z,1559235079.236 [DUSBL_Hydroid](INFO): Powering down
2019-05-30T16:51:19.327Z,1559235079.327 [Micromodem](INFO): uninitialize
2019-05-30T16:51:19.327Z,1559235079.327 [Micromodem](INFO): Powering down
2019-05-30T16:51:19.423Z,1559235079.423 [NAL9602](INFO): Powering down
2019-05-30T16:51:19.495Z,1559235079.495 [RDI_Pathfinder](INFO): Powering down
2019-05-30T16:51:19.496Z,1559235079.496 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-30T16:51:19.497Z,1559235079.497 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-30T16:51:19.498Z,1559235079.498 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-30T16:51:19.498Z,1559235079.498 [MissionManager](INFO): Uninitializing Mission Default
2019-05-30T16:51:19.498Z,1559235079.498 [Default] Stopped
2019-05-30T16:51:19.498Z,1559235079.498 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-30T16:51:19.498Z,1559235079.498 [Default:B.GoToSurface] Stopped
2019-05-30T16:51:19.499Z,1559235079.499 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T16:51:19.499Z,1559235079.499 [Default:CheckIn] Stopped
2019-05-30T16:51:19.499Z,1559235079.499 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T16:51:19.499Z,1559235079.499 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T16:51:19.501Z,1559235079.501 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-30T16:51:19.501Z,1559235079.501 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-30T16:51:19.502Z,1559235079.502 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-30T16:51:19.502Z,1559235079.502 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-30T16:51:19.502Z,1559235079.502 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-30T16:51:19.502Z,1559235079.502 [BuoyancyServo](INFO): Powering down
2019-05-30T16:51:19.515Z,1559235079.515 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-30T16:51:19.515Z,1559235079.515 [ElevatorServo](INFO): Powering down
2019-05-30T16:51:19.516Z,1559235079.516 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-30T16:51:19.516Z,1559235079.516 [MassServo](INFO): Powering down
2019-05-30T16:51:19.517Z,1559235079.517 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-30T16:51:19.517Z,1559235079.517 [RudderServo](INFO): Powering down
2019-05-30T16:51:19.518Z,1559235079.518 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-30T16:51:19.518Z,1559235079.518 [ThrusterServo](INFO): Powering down
2019-05-30T16:51:19.519Z,1559235079.519 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-30T16:51:19.519Z,1559235079.519 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-30T16:51:19.519Z,1559235079.519 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-30T16:51:19.519Z,1559235079.519 [CBIT](DEBUG): Powering off loads.
2019-05-30T16:51:19.531Z,1559235079.531 [CBIT](DEBUG): Disabling WDT.
2019-05-30T16:51:19.543Z,1559235079.543 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-30T16:51:19.544Z,1559235079.544 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.600Z,1559235079.600 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.641Z,1559235079.641 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.643Z,1559235079.643 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.698Z,1559235079.698 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:51:19.767Z,1559235079.767 [logger ThreadHandler](INFO): Thread cancelled.