2019-03-14T21:05:38.180Z,1552597538.180 [Supervisor](DEBUG): Initializing supervisor.
2019-03-14T21:05:38.183Z,1552597538.183 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-03-14T21:05:38.184Z,1552597538.184 [SyncHandler](INFO): Protected caller Thread ID is 1092
2019-03-14T21:05:38.185Z,1552597538.185 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-03-14T21:05:38.185Z,1552597538.185 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-03-14T21:05:38.186Z,1552597538.186 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1093
2019-03-14T21:05:38.189Z,1552597538.189 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-03-14T21:05:38.201Z,1552597538.201 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-03-14T21:05:38.202Z,1552597538.202 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-03-14T21:05:38.202Z,1552597538.202 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1094
2019-03-14T21:05:38.203Z,1552597538.203 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-03-14T21:05:38.204Z,1552597538.204 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-03-14T21:05:38.204Z,1552597538.204 [logger ThreadHandler](INFO): Protected caller Thread ID is 1095
2019-03-14T21:05:38.206Z,1552597538.206 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-03-14T21:05:38.207Z,1552597538.207 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-03-14T21:05:38.208Z,1552597538.208 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-03-14T21:05:38.650Z,1552597538.650 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-03-14T21:05:38.651Z,1552597538.651 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-03-14T21:05:38.749Z,1552597538.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-03-14T21:05:38.750Z,1552597538.750 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-03-14T21:05:39.091Z,1552597539.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-03-14T21:05:39.092Z,1552597539.092 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-03-14T21:05:39.239Z,1552597539.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-03-14T21:05:39.240Z,1552597539.240 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-03-14T21:05:39.439Z,1552597539.439 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-03-14T21:05:39.439Z,1552597539.439 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-03-14T21:05:39.999Z,1552597539.999 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-03-14T21:05:40.000Z,1552597540.000 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-03-14T21:05:40.219Z,1552597540.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-03-14T21:05:40.220Z,1552597540.220 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-03-14T21:05:40.370Z,1552597540.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-03-14T21:05:40.370Z,1552597540.370 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-03-14T21:05:40.575Z,1552597540.575 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-03-14T21:05:40.576Z,1552597540.576 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-03-14T21:05:40.674Z,1552597540.674 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-03-14T21:05:40.675Z,1552597540.675 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-03-14T21:05:40.997Z,1552597540.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-03-14T21:05:40.998Z,1552597540.998 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-03-14T21:05:41.079Z,1552597541.079 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-03-14T21:05:41.185Z,1552597541.185 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-03-14T21:05:41.185Z,1552597541.185 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-03-14T21:05:41.702Z,1552597541.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-03-14T21:05:41.703Z,1552597541.703 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-03-14T21:05:42.126Z,1552597542.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-03-14T21:05:42.128Z,1552597542.128 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-03-14T21:05:42.129Z,1552597542.129 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-03-14T21:05:42.347Z,1552597542.347 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-03-14T21:05:42.449Z,1552597542.449 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-03-14T21:05:42.550Z,1552597542.550 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-03-14T21:05:42.783Z,1552597542.783 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-03-14T21:05:42.783Z,1552597542.783 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-03-14T21:05:42.869Z,1552597542.869 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-03-14T21:05:42.964Z,1552597542.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-03-14T21:05:43.064Z,1552597543.064 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-03-14T21:05:43.147Z,1552597543.147 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-03-14T21:05:43.259Z,1552597543.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-03-14T21:05:43.439Z,1552597543.439 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-03-14T21:05:43.576Z,1552597543.576 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-03-14T21:05:43.576Z,1552597543.576 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-03-14T21:05:43.581Z,1552597543.581 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-03-14T21:05:43.900Z,1552597543.900 [DataOverHttps] Loaded
2019-03-14T21:05:43.900Z,1552597543.900 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-03-14T21:05:43.902Z,1552597543.902 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4074D4E0
2019-03-14T21:05:43.902Z,1552597543.902 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1174
2019-03-14T21:05:43.942Z,1552597543.942 [Depth_Keller] Loaded
2019-03-14T21:05:43.942Z,1552597543.942 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-03-14T21:05:43.947Z,1552597543.947 [DropWeight] Loaded
2019-03-14T21:05:43.948Z,1552597543.948 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-03-14T21:05:43.996Z,1552597543.996 [DUSBL_Hydroid] Loaded
2019-03-14T21:05:43.997Z,1552597543.997 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-03-14T21:05:44.038Z,1552597544.038 [Micromodem] Loaded
2019-03-14T21:05:44.039Z,1552597544.039 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-03-14T21:05:44.137Z,1552597544.137 [NAL9602] Loaded
2019-03-14T21:05:44.137Z,1552597544.137 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-03-14T21:05:44.153Z,1552597544.153 [Onboard] Loaded
2019-03-14T21:05:44.153Z,1552597544.153 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-03-14T21:05:44.160Z,1552597544.160 [Radio_Surface] Loaded
2019-03-14T21:05:44.160Z,1552597544.160 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-03-14T21:05:44.161Z,1552597544.161 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4077D4E0
2019-03-14T21:05:44.162Z,1552597544.162 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1175
2019-03-14T21:05:44.223Z,1552597544.223 [RDI_Pathfinder] Loaded
2019-03-14T21:05:44.223Z,1552597544.223 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-03-14T21:05:44.245Z,1552597544.245 [RDI_PathfinderUp] Loaded
2019-03-14T21:05:44.245Z,1552597544.245 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2019-03-14T21:05:46.562Z,1552597546.562 [BPC1] Loaded
2019-03-14T21:05:46.562Z,1552597546.562 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-03-14T21:05:46.563Z,1552597546.563 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-03-14T21:05:46.563Z,1552597546.563 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-03-14T21:05:46.751Z,1552597546.751 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-03-14T21:05:46.752Z,1552597546.752 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-03-14T21:05:46.859Z,1552597546.859 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-03-14T21:05:46.860Z,1552597546.860 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-03-14T21:05:46.920Z,1552597546.920 [DeadReckonUsingSpeedCalculator] Loaded
2019-03-14T21:05:46.920Z,1552597546.920 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-03-14T21:05:46.981Z,1552597546.981 [DeadReckonWithRespectToSeafloor] Loaded
2019-03-14T21:05:46.981Z,1552597546.981 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-03-14T21:05:47.002Z,1552597547.002 [NavChart] Loaded
2019-03-14T21:05:47.002Z,1552597547.002 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-03-14T21:05:47.006Z,1552597547.006 [UniversalFixResidualReporter] Loaded
2019-03-14T21:05:47.007Z,1552597547.007 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-03-14T21:05:47.007Z,1552597547.007 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-03-14T21:05:47.008Z,1552597547.008 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-03-14T21:05:47.112Z,1552597547.112 [BuoyancyServo] Loaded
2019-03-14T21:05:47.112Z,1552597547.112 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-03-14T21:05:47.128Z,1552597547.128 [ElevatorServo] Loaded
2019-03-14T21:05:47.128Z,1552597547.128 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-03-14T21:05:47.143Z,1552597547.143 [MassServo] Loaded
2019-03-14T21:05:47.143Z,1552597547.143 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-03-14T21:05:47.159Z,1552597547.159 [RudderServo] Loaded
2019-03-14T21:05:47.159Z,1552597547.159 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-03-14T21:05:47.174Z,1552597547.174 [ThrusterServo] Loaded
2019-03-14T21:05:47.174Z,1552597547.174 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-03-14T21:05:47.174Z,1552597547.174 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-03-14T21:05:47.175Z,1552597547.175 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-03-14T21:05:47.428Z,1552597547.428 [CTD_NeilBrown] Loaded
2019-03-14T21:05:47.428Z,1552597547.428 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-03-14T21:05:47.429Z,1552597547.429 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408C24E0
2019-03-14T21:05:47.429Z,1552597547.429 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1176
2019-03-14T21:05:47.475Z,1552597547.475 [WetLabsSeaOWL_UV_A] Loaded
2019-03-14T21:05:47.475Z,1552597547.475 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-03-14T21:05:47.476Z,1552597547.476 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408F24E0
2019-03-14T21:05:47.476Z,1552597547.476 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1177
2019-03-14T21:05:47.477Z,1552597547.477 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-03-14T21:05:47.477Z,1552597547.477 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-03-14T21:05:47.719Z,1552597547.719 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-03-14T21:05:47.719Z,1552597547.719 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-03-14T21:05:47.761Z,1552597547.761 [DepthRateCalculator] Loaded
2019-03-14T21:05:47.761Z,1552597547.761 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-03-14T21:05:47.767Z,1552597547.767 [PitchRateCalculator] Loaded
2019-03-14T21:05:47.767Z,1552597547.767 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-03-14T21:05:47.780Z,1552597547.780 [SpeedCalculator] Loaded
2019-03-14T21:05:47.780Z,1552597547.780 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-03-14T21:05:47.801Z,1552597547.801 [TempGradientCalculator] Loaded
2019-03-14T21:05:47.802Z,1552597547.802 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-03-14T21:05:47.808Z,1552597547.808 [YawRateCalculator] Loaded
2019-03-14T21:05:47.808Z,1552597547.808 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-03-14T21:05:47.849Z,1552597547.849 [ElevatorOffsetCalculator] Loaded
2019-03-14T21:05:47.849Z,1552597547.849 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-03-14T21:05:47.850Z,1552597547.850 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-03-14T21:05:47.850Z,1552597547.850 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-03-14T21:05:47.987Z,1552597547.987 [SBIT](DEBUG): Construct Startup Built In Test.
2019-03-14T21:05:48.010Z,1552597548.010 [SBIT] Loaded
2019-03-14T21:05:48.010Z,1552597548.010 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-03-14T21:05:48.011Z,1552597548.011 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-03-14T21:05:48.023Z,1552597548.023 [IBIT] Loaded
2019-03-14T21:05:48.023Z,1552597548.023 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-03-14T21:05:48.026Z,1552597548.026 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-03-14T21:05:48.168Z,1552597548.168 [CBIT] Loaded
2019-03-14T21:05:48.168Z,1552597548.168 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-03-14T21:05:48.169Z,1552597548.169 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-03-14T21:05:48.169Z,1552597548.169 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-03-14T21:05:48.232Z,1552597548.232 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-03-14T21:05:48.233Z,1552597548.233 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-03-14T21:05:48.332Z,1552597548.332 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-03-14T21:05:48.333Z,1552597548.333 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-03-14T21:05:48.400Z,1552597548.400 [VerticalControl](DEBUG): Construct VerticalControl.
2019-03-14T21:05:48.485Z,1552597548.485 [VerticalControl] Loaded
2019-03-14T21:05:48.486Z,1552597548.486 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-03-14T21:05:48.486Z,1552597548.486 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-03-14T21:05:48.545Z,1552597548.545 [HorizontalControl] Loaded
2019-03-14T21:05:48.546Z,1552597548.546 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-03-14T21:05:48.546Z,1552597548.546 [SpeedControl](DEBUG): Construct SpeedControl.
2019-03-14T21:05:48.548Z,1552597548.548 [SpeedControl] Loaded
2019-03-14T21:05:48.548Z,1552597548.548 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-03-14T21:05:48.549Z,1552597548.549 [LoopControl](DEBUG): Construct LoopControl.
2019-03-14T21:05:48.550Z,1552597548.550 [LoopControl] Loaded
2019-03-14T21:05:48.550Z,1552597548.550 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-03-14T21:05:48.550Z,1552597548.550 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-03-14T21:05:48.551Z,1552597548.551 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-03-14T21:05:48.578Z,1552597548.578 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-03-14T21:05:48.581Z,1552597548.581 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-03-14T21:05:48.582Z,1552597548.582 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-03-14T21:05:48.589Z,1552597548.589 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-03-14T21:05:48.590Z,1552597548.590 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AB04E0
2019-03-14T21:05:48.591Z,1552597548.591 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1178
2019-03-14T21:05:48.595Z,1552597548.595 [Supervisor](INFO): Main Thread ID is 800
2019-03-14T21:05:48.595Z,1552597548.595 [Supervisor](DEBUG): Running supervisor.
2019-03-14T21:05:48.596Z,1552597548.596 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1179
2019-03-14T21:05:48.598Z,1552597548.598 [controlThread ThreadHandler](INFO): Handler Thread ID is 1180
2019-03-14T21:05:48.599Z,1552597548.599 [controlThread](DEBUG): Initializing ControlThread
2019-03-14T21:05:48.605Z,1552597548.605 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-14T21:05:48.606Z,1552597548.606 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-03-14T21:05:48.607Z,1552597548.607 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-03-14T21:05:48.608Z,1552597548.608 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-03-14T21:05:48.608Z,1552597548.608 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-03-14T21:05:48.608Z,1552597548.608 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-03-14T21:05:48.608Z,1552597548.608 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-03-14T21:05:48.609Z,1552597548.609 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-03-14T21:05:48.609Z,1552597548.609 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-03-14T21:05:48.610Z,1552597548.610 [SBIT](INFO): Initialize SBIT Component.
2019-03-14T21:05:48.611Z,1552597548.611 [SBIT](IMPORTANT): git: 2019-03-04-36-g743def3
2019-03-14T21:05:48.611Z,1552597548.611 [SBIT](INFO): git hash: 743def31acf12ef8e20e672f0fefb031590b97fa
2019-03-14T21:05:48.611Z,1552597548.611 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-03-14T21:05:48.611Z,1552597548.611 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2019-03-14T21:05:48.612Z,1552597548.612 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-03-14T21:05:48.613Z,1552597548.613 [IBIT](INFO): Initialize IBIT Component.
2019-03-14T21:05:48.614Z,1552597548.614 [CBIT](DEBUG): Initialize CBIT Component.
2019-03-14T21:05:48.615Z,1552597548.615 [logger ThreadHandler](INFO): Handler Thread ID is 1181
2019-03-14T21:05:48.626Z,1552597548.626 [CBIT](DEBUG): Initialized mux pins.
2019-03-14T21:05:48.626Z,1552597548.626 [CBIT](DEBUG): Initializing the watchdog timer.
2019-03-14T21:05:48.635Z,1552597548.635 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1182
2019-03-14T21:05:48.636Z,1552597548.636 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-03-14T21:05:48.647Z,1552597548.647 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1183
2019-03-14T21:05:48.650Z,1552597548.650 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2019-03-14T21:05:48.650Z,1552597548.650 [CBIT](DEBUG): Initializing heartbeat.
2019-03-14T21:05:48.659Z,1552597548.659 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1184
2019-03-14T21:05:48.659Z,1552597548.659 [CTD_NeilBrown](INFO): Powering down
2019-03-14T21:05:48.687Z,1552597548.687 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1185
2019-03-14T21:05:48.687Z,1552597548.687 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-03-14T21:05:48.719Z,1552597548.719 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1186
2019-03-14T21:05:48.722Z,1552597548.722 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-03-14T21:05:48.722Z,1552597548.722 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-03-14T21:05:48.722Z,1552597548.722 [CBIT](DEBUG): Deactivating GF circuits.
2019-03-14T21:05:48.723Z,1552597548.723 [CBIT](DEBUG): Deactivating emergency mode.
2019-03-14T21:05:48.723Z,1552597548.723 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-03-14T21:05:48.723Z,1552597548.723 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-03-14T21:05:48.724Z,1552597548.724 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-03-14T21:05:48.724Z,1552597548.724 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-03-14T21:05:48.724Z,1552597548.724 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-03-14T21:05:48.724Z,1552597548.724 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-03-14T21:05:48.724Z,1552597548.724 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-03-14T21:05:48.724Z,1552597548.724 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-03-14T21:05:48.725Z,1552597548.725 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-03-14T21:05:48.725Z,1552597548.725 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-03-14T21:05:48.725Z,1552597548.725 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-03-14T21:05:48.725Z,1552597548.725 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-03-14T21:05:48.725Z,1552597548.725 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-03-14T21:05:48.726Z,1552597548.726 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-03-14T21:05:48.758Z,1552597548.758 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-03-14T21:05:48.760Z,1552597548.760 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-03-14T21:05:48.761Z,1552597548.761 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-03-14T21:05:48.761Z,1552597548.761 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-03-14T21:05:48.762Z,1552597548.762 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-03-14T21:05:48.772Z,1552597548.772 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-03-14T21:05:48.796Z,1552597548.796 [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-03-14T21:05:48.797Z,1552597548.797 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-03-14T21:05:48.872Z,1552597548.872 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-03-14T21:05:48.873Z,1552597548.873 [Default:A.Wait](DEBUG): Construct Wait.
2019-03-14T21:05:48.874Z,1552597548.874 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-03-14T21:05:48.901Z,1552597548.901 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-03-14T21:05:48.924Z,1552597548.924 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-03-14T21:05:48.929Z,1552597548.929 [Default:E.Execute](DEBUG): Construct Execute.
2019-03-14T21:05:48.949Z,1552597548.949 [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-03-14T21:05:48.954Z,1552597548.954 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,RDI_Pathfinder,RDI_PathfinderUp,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-03-14T21:05:48.994Z,1552597548.994 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-03-14T21:05:48.995Z,1552597548.995 [DUSBL_Hydroid](INFO): Powering up
2019-03-14T21:05:48.995Z,1552597548.995 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-03-14T21:05:49.018Z,1552597549.018 [Micromodem](INFO): Start
2019-03-14T21:05:49.050Z,1552597549.050 [Radio_Surface](INFO): Powering up
2019-03-14T21:05:49.082Z,1552597549.082 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-03-14T21:05:49.103Z,1552597549.103 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-03-14T21:05:49.111Z,1552597549.111 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-03-14T21:05:49.112Z,1552597549.112 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-03-14T21:05:49.126Z,1552597549.126 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-03-14T21:05:49.127Z,1552597549.127 [MassServo](DEBUG): Initializing EZServoServo.
2019-03-14T21:05:49.134Z,1552597549.134 [MassServo](DEBUG): Initializing MassServo.
2019-03-14T21:05:49.135Z,1552597549.135 [RudderServo](DEBUG): Initializing EZServoServo.
2019-03-14T21:05:49.142Z,1552597549.142 [RudderServo](DEBUG): Initializing RudderServo.
2019-03-14T21:05:49.143Z,1552597549.143 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-03-14T21:05:49.154Z,1552597549.154 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-03-14T21:05:49.156Z,1552597549.156 [CommandLine](FAULT): Scheduling is paused
2019-03-14T21:05:49.157Z,1552597549.157 [CBIT](INFO): Critical error at 20190314T210548
2019-03-14T21:05:49.157Z,1552597549.157 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-03-14T21:05:49.380Z,1552597549.380 [Micromodem](INFO): Starting
2019-03-14T21:05:49.380Z,1552597549.380 [Micromodem](INFO): Powering up
2019-03-14T21:05:49.380Z,1552597549.380 [Micromodem](DEBUG): Initializing Micromodem.
2019-03-14T21:05:49.478Z,1552597549.478 [RDI_PathfinderUp](INFO): Powering down
2019-03-14T21:05:49.511Z,1552597549.511 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-03-14T21:05:49.771Z,1552597549.771 [Micromodem](INFO): Starting
2019-03-14T21:05:49.790Z,1552597549.790 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-03-14T21:05:50.176Z,1552597550.176 [Micromodem](INFO): Starting
2019-03-14T21:05:50.580Z,1552597550.580 [Micromodem](INFO): Starting
2019-03-14T21:05:50.984Z,1552597550.984 [Micromodem](INFO): Starting
2019-03-14T21:05:51.388Z,1552597551.388 [Micromodem](INFO): Starting
2019-03-14T21:05:51.792Z,1552597551.792 [Micromodem](INFO): Starting
2019-03-14T21:05:52.196Z,1552597552.196 [Micromodem](INFO): Starting
2019-03-14T21:05:52.600Z,1552597552.600 [Micromodem](INFO): Starting
2019-03-14T21:05:53.004Z,1552597553.004 [Micromodem](INFO): Starting
2019-03-14T21:05:53.408Z,1552597553.408 [Micromodem](INFO): Starting
2019-03-14T21:05:53.812Z,1552597553.812 [Micromodem](INFO): Starting
2019-03-14T21:05:54.216Z,1552597554.216 [Micromodem](INFO): Starting
2019-03-14T21:05:54.216Z,1552597554.216 [Micromodem](INFO): Starting
2019-03-14T21:05:54.216Z,1552597554.216 [Micromodem](DEBUG): Nmea buf: $CCCFG,ALL,0*33

2019-03-14T21:05:54.216Z,1552597554.216 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,ALL,0*33

2019-03-14T21:05:54.217Z,1552597554.217 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-03-14T21:05:54.217Z,1552597554.217 [Micromodem](DEBUG): Nmea buf: $CCCFG,SRC,1*31

2019-03-14T21:05:54.217Z,1552597554.217 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,SRC,1*31

2019-03-14T21:05:54.217Z,1552597554.217 [Micromodem](DEBUG): Nmea buf: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-03-14T21:05:54.218Z,1552597554.218 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-03-14T21:05:54.218Z,1552597554.218 [Micromodem](DEBUG): Nmea buf: $CCCFG,BND,1*3B

2019-03-14T21:05:54.219Z,1552597554.219 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,BND,1*3B

2019-03-14T21:05:54.620Z,1552597554.620 [Micromodem](INFO): Starting
2019-03-14T21:05:55.024Z,1552597555.024 [Micromodem](INFO): Starting
2019-03-14T21:05:55.429Z,1552597555.429 [Micromodem](INFO): Starting
2019-03-14T21:05:55.832Z,1552597555.832 [Micromodem](INFO): Starting
2019-03-14T21:05:56.236Z,1552597556.236 [Micromodem](INFO): Starting
2019-03-14T21:05:56.640Z,1552597556.640 [Micromodem](INFO): Starting
2019-03-14T21:05:57.045Z,1552597557.045 [Micromodem](INFO): Starting
2019-03-14T21:05:57.460Z,1552597557.460 [Micromodem](INFO): Starting
2019-03-14T21:05:57.852Z,1552597557.852 [Micromodem](INFO): Starting
2019-03-14T21:05:58.260Z,1552597558.260 [Micromodem](INFO): Starting
2019-03-14T21:05:58.660Z,1552597558.660 [Micromodem](INFO): Starting
2019-03-14T21:05:59.064Z,1552597559.064 [Micromodem](INFO): Starting
2019-03-14T21:05:59.476Z,1552597559.476 [Micromodem](INFO): Starting
2019-03-14T21:05:59.872Z,1552597559.872 [Micromodem](INFO): Starting
2019-03-14T21:06:00.276Z,1552597560.276 [Micromodem](INFO): Starting
2019-03-14T21:06:00.680Z,1552597560.680 [Micromodem](INFO): Starting
2019-03-14T21:06:01.084Z,1552597561.084 [Micromodem](INFO): Starting
2019-03-14T21:06:01.488Z,1552597561.488 [Micromodem](INFO): Starting
2019-03-14T21:06:01.892Z,1552597561.892 [Micromodem](INFO): Starting
2019-03-14T21:06:02.296Z,1552597562.296 [Micromodem](INFO): Starting
2019-03-14T21:06:02.331Z,1552597562.331 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-03-14T21:06:02.700Z,1552597562.700 [Micromodem](INFO): Starting
2019-03-14T21:06:03.111Z,1552597563.111 [Micromodem](INFO): Starting
2019-03-14T21:06:03.518Z,1552597563.518 [Micromodem](INFO): Starting
2019-03-14T21:06:03.912Z,1552597563.912 [Micromodem](INFO): Starting
2019-03-14T21:06:04.316Z,1552597564.316 [Micromodem](INFO): Starting
2019-03-14T21:06:04.720Z,1552597564.720 [Micromodem](INFO): Starting
2019-03-14T21:06:05.127Z,1552597565.127 [Micromodem](INFO): Starting
2019-03-14T21:06:05.528Z,1552597565.528 [Micromodem](INFO): Starting
2019-03-14T21:06:05.532Z,1552597565.532 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-03-14T21:06:05.932Z,1552597565.932 [Micromodem](INFO): Starting
2019-03-14T21:06:06.336Z,1552597566.336 [Micromodem](INFO): Starting
2019-03-14T21:06:06.741Z,1552597566.741 [Micromodem](INFO): Starting
2019-03-14T21:06:07.144Z,1552597567.144 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-03-14T21:06:07.159Z,1552597567.159 [Micromodem](INFO): Starting
2019-03-14T21:06:07.547Z,1552597567.547 [Micromodem](INFO): Starting
2019-03-14T21:06:07.952Z,1552597567.952 [Micromodem](INFO): Starting
2019-03-14T21:06:08.355Z,1552597568.355 [Micromodem](INFO): Starting
2019-03-14T21:06:08.759Z,1552597568.759 [Micromodem](INFO): Starting
2019-03-14T21:06:09.166Z,1552597569.166 [Micromodem](INFO): Starting
2019-03-14T21:06:09.568Z,1552597569.568 [Micromodem](INFO): Starting
2019-03-14T21:06:09.972Z,1552597569.972 [Micromodem](INFO): Starting
2019-03-14T21:06:10.391Z,1552597570.391 [Micromodem](INFO): Starting
2019-03-14T21:06:10.779Z,1552597570.779 [Micromodem](INFO): Starting
2019-03-14T21:06:11.183Z,1552597571.183 [Micromodem](INFO): Starting
2019-03-14T21:06:11.587Z,1552597571.587 [Micromodem](INFO): Starting
2019-03-14T21:06:11.991Z,1552597571.991 [Micromodem](INFO): Starting
2019-03-14T21:06:12.395Z,1552597572.395 [Micromodem](INFO): Starting
2019-03-14T21:06:12.800Z,1552597572.800 [Micromodem](INFO): Starting
2019-03-14T21:06:13.203Z,1552597573.203 [Micromodem](INFO): Starting
2019-03-14T21:06:13.607Z,1552597573.607 [Micromodem](INFO): Starting
2019-03-14T21:06:14.011Z,1552597574.011 [Micromodem](INFO): Starting
2019-03-14T21:06:14.012Z,1552597574.012 [Micromodem](IMPORTANT): CACFG stsring$CACFG,ALL,0*31

2019-03-14T21:06:14.013Z,1552597574.013 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-03-14T21:06:14.415Z,1552597574.415 [Micromodem](INFO): Starting
2019-03-14T21:06:14.417Z,1552597574.417 [NAL9602](INFO): Powering up NAL9602
2019-03-14T21:06:14.817Z,1552597574.817 [Micromodem](INFO): Starting
2019-03-14T21:06:15.223Z,1552597575.223 [Micromodem](INFO): Starting
2019-03-14T21:06:15.627Z,1552597575.627 [Micromodem](INFO): Starting
2019-03-14T21:06:16.031Z,1552597576.031 [Micromodem](INFO): Starting
2019-03-14T21:06:16.435Z,1552597576.435 [Micromodem](INFO): Starting
2019-03-14T21:06:16.839Z,1552597576.839 [Micromodem](INFO): Starting
2019-03-14T21:06:17.243Z,1552597577.243 [Micromodem](INFO): Starting
2019-03-14T21:06:17.288Z,1552597577.288 [SBIT](IMPORTANT): Beginning Startup BIT
2019-03-14T21:06:17.297Z,1552597577.297 [CBIT](IMPORTANT): Beginning ground fault scan
2019-03-14T21:06:17.648Z,1552597577.648 [Micromodem](INFO): Starting
2019-03-14T21:06:18.051Z,1552597578.051 [Micromodem](INFO): Starting
2019-03-14T21:06:18.457Z,1552597578.457 [Micromodem](INFO): Starting
2019-03-14T21:06:18.859Z,1552597578.859 [Micromodem](INFO): Starting
2019-03-14T21:06:19.263Z,1552597579.263 [Micromodem](INFO): Starting
2019-03-14T21:06:19.791Z,1552597579.791 [Micromodem](INFO): Starting
2019-03-14T21:06:20.191Z,1552597580.191 [Micromodem](INFO): Starting
2019-03-14T21:06:20.595Z,1552597580.595 [Micromodem](INFO): Starting
2019-03-14T21:06:20.999Z,1552597580.999 [Micromodem](INFO): Starting
2019-03-14T21:06:21.403Z,1552597581.403 [Micromodem](INFO): Starting
2019-03-14T21:06:21.808Z,1552597581.808 [Micromodem](INFO): Starting
2019-03-14T21:06:22.211Z,1552597582.211 [Micromodem](INFO): Starting
2019-03-14T21:06:22.615Z,1552597582.615 [Micromodem](INFO): Starting
2019-03-14T21:06:23.019Z,1552597583.019 [Micromodem](INFO): Starting
2019-03-14T21:06:23.423Z,1552597583.423 [Micromodem](INFO): Starting
2019-03-14T21:06:23.827Z,1552597583.827 [Micromodem](INFO): Starting
2019-03-14T21:06:24.231Z,1552597584.231 [Micromodem](INFO): Starting
2019-03-14T21:06:24.232Z,1552597584.232 [Micromodem](IMPORTANT): CACFG stsring$CACFG,SRC,1*33

2019-03-14T21:06:24.232Z,1552597584.232 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-03-14T21:06:24.635Z,1552597584.635 [Micromodem](INFO): Starting
2019-03-14T21:06:25.039Z,1552597585.039 [Micromodem](INFO): Starting
2019-03-14T21:06:25.443Z,1552597585.443 [Micromodem](INFO): Starting
2019-03-14T21:06:25.444Z,1552597585.444 [NAL9602](INFO): NAL9602 initialized
2019-03-14T21:06:25.847Z,1552597585.847 [Micromodem](INFO): Starting
2019-03-14T21:06:26.260Z,1552597586.260 [Micromodem](INFO): Starting
2019-03-14T21:06:26.274Z,1552597586.274 [NAL9602](DEBUG): Fix Requested
2019-03-14T21:06:26.655Z,1552597586.655 [Micromodem](INFO): Starting
2019-03-14T21:06:27.059Z,1552597587.059 [Micromodem](INFO): Starting
2019-03-14T21:06:27.463Z,1552597587.463 [Micromodem](INFO): Starting
2019-03-14T21:06:27.868Z,1552597587.868 [Micromodem](INFO): Starting
2019-03-14T21:06:28.271Z,1552597588.271 [Micromodem](INFO): Starting
2019-03-14T21:06:28.383Z,1552597588.383 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.014838
CHAN A1 (24V): -0.026613
CHAN A2 (12V): -0.006935
CHAN A3 (5V): -0.002221
CHAN B0 (3.3V): 0.000646
CHAN B1 (3.15aV): -0.000246
CHAN B2 (3.15bV): 0.000305
CHAN B3 (GND): 0.002009
OPEN: 0.006736
Full Scale Calc: 4.765 mA, -1.589 mA
2019-03-14T21:06:28.675Z,1552597588.675 [Micromodem](INFO): Starting
2019-03-14T21:06:29.081Z,1552597589.081 [Micromodem](INFO): Starting
2019-03-14T21:06:29.480Z,1552597589.480 [Micromodem](INFO): Starting
2019-03-14T21:06:29.887Z,1552597589.887 [Micromodem](INFO): Starting
2019-03-14T21:06:30.291Z,1552597590.291 [Micromodem](INFO): Starting
2019-03-14T21:06:30.695Z,1552597590.695 [Micromodem](INFO): Starting
2019-03-14T21:06:31.099Z,1552597591.099 [Micromodem](INFO): Starting
2019-03-14T21:06:31.514Z,1552597591.514 [Micromodem](INFO): Starting
2019-03-14T21:06:31.907Z,1552597591.907 [Micromodem](INFO): Starting
2019-03-14T21:06:32.312Z,1552597592.312 [Micromodem](INFO): Starting
2019-03-14T21:06:32.715Z,1552597592.715 [Micromodem](INFO): Starting
2019-03-14T21:06:33.211Z,1552597593.211 [Micromodem](INFO): Starting
2019-03-14T21:06:33.611Z,1552597593.611 [Micromodem](INFO): Starting
2019-03-14T21:06:34.015Z,1552597594.015 [Micromodem](INFO): Starting
2019-03-14T21:06:34.016Z,1552597594.016 [Micromodem](IMPORTANT): CACFG stsring$CACFG,nav.dt.txtrig_gpio4,1*66

2019-03-14T21:06:34.017Z,1552597594.017 [Micromodem](INFO): Nmea out: $CCCFG,BND,1*3B

2019-03-14T21:06:34.419Z,1552597594.419 [Micromodem](INFO): Starting
2019-03-14T21:06:34.823Z,1552597594.823 [Micromodem](INFO): Starting
2019-03-14T21:06:35.227Z,1552597595.227 [Micromodem](INFO): Starting
2019-03-14T21:06:35.631Z,1552597595.631 [Micromodem](INFO): Starting
2019-03-14T21:06:36.036Z,1552597596.036 [Micromodem](INFO): Starting
2019-03-14T21:06:36.439Z,1552597596.439 [Micromodem](INFO): Starting
2019-03-14T21:06:36.843Z,1552597596.843 [Micromodem](INFO): Starting
2019-03-14T21:06:37.247Z,1552597597.247 [Micromodem](INFO): Starting
2019-03-14T21:06:37.651Z,1552597597.651 [Micromodem](INFO): Starting
2019-03-14T21:06:38.055Z,1552597598.055 [Micromodem](INFO): Starting
2019-03-14T21:06:38.459Z,1552597598.459 [Micromodem](INFO): Starting
2019-03-14T21:06:38.872Z,1552597598.872 [Micromodem](INFO): Starting
2019-03-14T21:06:39.267Z,1552597599.267 [Micromodem](INFO): Starting
2019-03-14T21:06:39.671Z,1552597599.671 [Micromodem](INFO): Starting
2019-03-14T21:06:40.075Z,1552597600.075 [Micromodem](INFO): Starting
2019-03-14T21:06:40.482Z,1552597600.482 [Micromodem](INFO): Starting
2019-03-14T21:06:40.883Z,1552597600.883 [Micromodem](INFO): Starting
2019-03-14T21:06:41.287Z,1552597601.287 [Micromodem](INFO): Starting
2019-03-14T21:06:41.691Z,1552597601.691 [Micromodem](INFO): Starting
2019-03-14T21:06:42.095Z,1552597602.095 [Micromodem](INFO): Starting
2019-03-14T21:06:42.499Z,1552597602.499 [Micromodem](INFO): Starting
2019-03-14T21:06:42.903Z,1552597602.903 [Micromodem](INFO): Starting
2019-03-14T21:06:43.307Z,1552597603.307 [Micromodem](INFO): Starting
2019-03-14T21:06:43.711Z,1552597603.711 [Micromodem](INFO): Starting
2019-03-14T21:06:44.119Z,1552597604.119 [Micromodem](INFO): Starting
2019-03-14T21:06:44.120Z,1552597604.120 [Micromodem](IMPORTANT): CACFG stsring$CACFG,BND,1*39

2019-03-14T21:06:44.121Z,1552597604.121 [Micromodem](DEBUG): Nmea buf: $CCTMS,2019-03-14T21:06:45Z,0*7C

2019-03-14T21:06:44.121Z,1552597604.121 [Micromodem](IMPORTANT): Nmea buf: $CCTMS,2019-03-14T21:06:45Z,0*7C

2019-03-14T21:06:44.121Z,1552597604.121 [Micromodem](INFO): Nmea out: $CCTMS,2019-03-14T21:06:45Z,0*7C

2019-03-14T21:06:44.519Z,1552597604.519 [Micromodem](INFO): Starting
2019-03-14T21:06:44.923Z,1552597604.923 [Micromodem](INFO): Starting
2019-03-14T21:06:45.324Z,1552597605.324 [Micromodem](INFO): Starting
2019-03-14T21:07:10.927Z,1552597630.927 [SBIT](IMPORTANT): SBIT PASSED
2019-03-14T21:07:10.976Z,1552597630.976 [CommandLine](IMPORTANT): got command configSet list
2019-03-14T21:07:10.976Z,1552597630.976 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-03-14T21:07:10.977Z,1552597630.977 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;

2019-03-14T21:07:10.977Z,1552597630.977 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-03-14T21:07:10.977Z,1552597630.977 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=30 count;

2019-03-14T21:07:11.326Z,1552597631.326 [MissionManager](IMPORTANT): Started mission Startup
2019-03-14T21:07:11.326Z,1552597631.326 [Startup] Running Loop=1
2019-03-14T21:07:11.326Z,1552597631.326 [Startup](DEBUG): Aggregate::initialize Startup
2019-03-14T21:07:11.327Z,1552597631.327 [Startup:A.GoToSurface] Running Loop=1
2019-03-14T21:07:11.327Z,1552597631.327 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-14T21:07:11.328Z,1552597631.328 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-14T21:07:11.328Z,1552597631.328 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-14T21:07:11.329Z,1552597631.329 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-14T21:07:11.329Z,1552597631.329 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-14T21:07:11.330Z,1552597631.330 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-14T21:07:11.332Z,1552597631.332 [Startup:StartupSatComms] Running Loop=1
2019-03-14T21:07:11.332Z,1552597631.332 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-03-14T21:07:11.332Z,1552597631.332 [Startup:StartupSatComms:A] Running Loop=1
2019-03-14T21:07:11.735Z,1552597631.735 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-03-14T21:07:18.928Z,1552597638.928 [CommandLine](IMPORTANT): got command show variable turnaround
2019-03-14T21:07:19.051Z,1552597639.051 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (millisecond)
2019-03-14T21:07:32.956Z,1552597652.956 [CommandLine](IMPORTANT): got command get DUSBL_Hydroid.defaultTurnAroundTime
2019-03-14T21:07:32.957Z,1552597652.957 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime 50.000000 ms
2019-03-14T21:07:48.877Z,1552597668.877 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:07:48.877Z,1552597668.877 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-03-14T21:07:48.878Z,1552597668.878 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-14T21:07:48.883Z,1552597668.883 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:07:48.883Z,1552597668.883 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-03-14T21:07:48.883Z,1552597668.883 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-14T21:07:48.885Z,1552597668.885 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:07:48.885Z,1552597668.885 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-03-14T21:07:48.885Z,1552597668.885 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-14T21:07:48.904Z,1552597668.904 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-14T21:07:48.904Z,1552597668.904 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-14T21:07:48.904Z,1552597668.904 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-14T21:07:49.301Z,1552597669.301 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-14T21:07:49.301Z,1552597669.301 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-03-14T21:07:49.303Z,1552597669.303 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-14T21:07:49.303Z,1552597669.303 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-03-14T21:07:49.304Z,1552597669.304 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-14T21:07:49.304Z,1552597669.304 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-03-14T21:07:49.825Z,1552597669.825 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-14T21:07:56.780Z,1552597676.780 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2019-03-14T21:08:06.912Z,1552597686.912 [CommandLine](IMPORTANT): got command show stack
2019-03-14T21:08:06.912Z,1552597686.912 [CommandLine](IMPORTANT): Behavior Stack:

2019-03-14T21:08:06.912Z,1552597686.912 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2019-03-14T21:08:06.912Z,1552597686.912 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:A
2019-03-14T21:08:11.521Z,1552597691.521 [Startup:StartupSatComms:A](INFO): Timed out from 2019-03-14T21:07:11.3Z
2019-03-14T21:08:11.521Z,1552597691.521 [Startup:StartupSatComms:A] Stopped
2019-03-14T21:08:11.521Z,1552597691.521 [Startup:StartupSatComms:B] Running Loop=1
2019-03-14T21:08:11.924Z,1552597691.924 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-03-14T21:08:14.963Z,1552597694.963 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2019-03-14T21:08:15.099Z,1552597695.099 [Startup:StartupSatComms:B] Stopped
2019-03-14T21:08:15.099Z,1552597695.099 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-03-14T21:08:15.100Z,1552597695.100 [Startup:StartupSatComms] Stopped
2019-03-14T21:08:15.100Z,1552597695.100 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-03-14T21:08:15.100Z,1552597695.100 [Startup](INFO): Completed Startup
2019-03-14T21:08:15.101Z,1552597695.101 [MissionManager](INFO): Startup is completed.
2019-03-14T21:08:15.101Z,1552597695.101 [MissionManager](INFO): Uninitializing Mission Startup
2019-03-14T21:08:15.101Z,1552597695.101 [Startup] Stopped
2019-03-14T21:08:15.101Z,1552597695.101 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-03-14T21:08:15.101Z,1552597695.101 [Startup:A.GoToSurface] Stopped
2019-03-14T21:08:15.101Z,1552597695.101 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-14T21:08:15.539Z,1552597695.539 [MissionManager](IMPORTANT): Started mission Default
2019-03-14T21:08:15.540Z,1552597695.540 [Default] Running Loop=1
2019-03-14T21:08:15.540Z,1552597695.540 [Default](DEBUG): Aggregate::initialize Default
2019-03-14T21:08:15.540Z,1552597695.540 [Default:B.GoToSurface] Running Loop=1
2019-03-14T21:08:15.540Z,1552597695.540 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-14T21:08:15.540Z,1552597695.540 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-14T21:08:15.541Z,1552597695.541 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-14T21:08:15.541Z,1552597695.541 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-14T21:08:15.541Z,1552597695.541 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-14T21:08:15.542Z,1552597695.542 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-14T21:08:15.546Z,1552597695.546 [Default:A.Wait] Running Loop=1
2019-03-14T21:08:15.546Z,1552597695.546 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:08:17.012Z,1552597697.012 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004501
2019-03-14T21:08:28.836Z,1552597708.836 [Default:A.Wait](INFO): Done Waiting.
2019-03-14T21:08:28.836Z,1552597708.836 [Default:A.Wait] Stopped
2019-03-14T21:08:28.836Z,1552597708.836 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:08:29.220Z,1552597709.220 [Default:CheckIn] Running Loop=1
2019-03-14T21:08:29.221Z,1552597709.221 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-03-14T21:08:29.221Z,1552597709.221 [Default:CheckIn:Read_GPS] Running Loop=1
2019-03-14T21:08:29.634Z,1552597709.634 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-03-14T21:08:45.996Z,1552597725.996 [CommandLine](IMPORTANT): got command show variable dusbl
2019-03-14T21:08:46.075Z,1552597726.075 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-03-14T21:08:46.075Z,1552597726.075 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-03-14T21:08:46.076Z,1552597726.076 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (millisecond)
2019-03-14T21:08:46.076Z,1552597726.076 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-03-14T21:08:46.076Z,1552597726.076 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-03-14T21:08:46.077Z,1552597726.077 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-03-14T21:08:46.077Z,1552597726.077 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-03-14T21:08:46.078Z,1552597726.078 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-03-14T21:08:46.082Z,1552597726.082 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-03-14T21:08:46.082Z,1552597726.082 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-03-14T21:08:46.083Z,1552597726.083 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-03-14T21:08:46.083Z,1552597726.083 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-03-14T21:08:46.108Z,1552597726.108 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-03-14T21:08:46.108Z,1552597726.108 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-03-14T21:08:46.108Z,1552597726.108 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-03-14T21:08:46.116Z,1552597726.116 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (enum)
2019-03-14T21:08:46.116Z,1552597726.116 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-03-14T21:08:46.117Z,1552597726.117 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-03-14T21:08:46.117Z,1552597726.117 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-03-14T21:08:46.117Z,1552597726.117 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-03-14T21:08:46.118Z,1552597726.118 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-03-14T21:08:46.123Z,1552597726.123 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-03-14T21:08:46.124Z,1552597726.124 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-03-14T21:08:46.125Z,1552597726.125 [CommandLine](IMPORTANT): DUSBL_Hydroid.range (meter)
2019-03-14T21:08:46.125Z,1552597726.125 [CommandLine](IMPORTANT): DUSBL_Hydroid.direction (none)
2019-03-14T21:09:00.776Z,1552597740.776 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.range
2019-03-14T21:09:21.904Z,1552597761.904 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.xAngle
2019-03-14T21:09:24.171Z,1552597764.171 [NAL9602](INFO): SBD MO Status=0, MOMSN=2278, MT Status=0, MTMSN=0
2019-03-14T21:09:24.171Z,1552597764.171 [NAL9602](INFO): No messages in MT queue
2019-03-14T21:09:24.962Z,1552597764.962 [NAL9602](DEBUG): Fix Requested
2019-03-14T21:09:28.194Z,1552597768.194 [NAL9602](DEBUG): Fix Requested
2019-03-14T21:09:31.018Z,1552597771.018 [NAL9602](DEBUG): Fix Requested
2019-03-14T21:09:31.414Z,1552597771.414 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210401.00,A,3648.16361,N,12147.28759,W,0.350,145.69,140319,,,A*77
2019-03-14T21:09:31.417Z,1552597771.417 [NAL9602](INFO): GPS fix at 20190314T210401: (36.802727, -121.788127)
2019-03-14T21:09:31.445Z,1552597771.445 [Default:CheckIn:Read_GPS] Stopped
2019-03-14T21:09:31.446Z,1552597771.446 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-03-14T21:09:31.907Z,1552597771.907 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-03-14T21:09:39.446Z,1552597779.446 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190314T204042/Courier0010.lzma
2019-03-14T21:09:40.252Z,1552597780.252 [DataOverHttps](INFO): Moved sent file to Logs/20190314T204042/Courier0010.lzma.bak
2019-03-14T21:09:40.252Z,1552597780.252 [DataOverHttps](INFO): SBD MOMSN=10139733
2019-03-14T21:09:42.493Z,1552597782.493 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-03-14T21:09:42.493Z,1552597782.493 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-03-14T21:09:42.626Z,1552597782.626 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-03-14T21:09:42.633Z,1552597782.633 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-03-14T21:09:42.641Z,1552597782.641 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-03-14T21:09:42.649Z,1552597782.649 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-03-14T21:09:42.657Z,1552597782.657 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = 1.000000 bool
2019-03-14T21:09:42.663Z,1552597782.663 [DUSBL:A.Pitch](DEBUG): Construct.
2019-03-14T21:09:42.693Z,1552597782.693 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-03-14T21:09:42.726Z,1552597782.726 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-03-14T21:09:42.737Z,1552597782.737 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

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

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

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

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

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

    <Timeout Duration="MissionTimeout"/>

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

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

    <ReadData>
        <While>
            <Arg Name="EnabledDUSBL"/>
        </While>
        <Sensor:DUSBL_Hydroid.range/>
        <Sensor:DUSBL_Hydroid.direction/>
    </ReadData>
    
      <Aggregate Id="RequestRepeater">

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


2019-03-14T21:09:42.756Z,1552597782.756 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-03-14T21:09:42.931Z,1552597782.931 [Default] Stopped
2019-03-14T21:09:42.931Z,1552597782.931 [Default](DEBUG): Aggregate::uninitialize Default
2019-03-14T21:09:42.931Z,1552597782.931 [Default:B.GoToSurface] Stopped
2019-03-14T21:09:42.931Z,1552597782.931 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-14T21:09:42.931Z,1552597782.931 [Default:CheckIn] Stopped
2019-03-14T21:09:42.932Z,1552597782.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-03-14T21:09:42.932Z,1552597782.932 [Default:CheckIn:Read_Iridium] Stopped
2019-03-14T21:09:42.932Z,1552597782.932 [MissionManager](IMPORTANT): Started mission DUSBL
2019-03-14T21:09:42.932Z,1552597782.932 [DUSBL] Running Loop=1
2019-03-14T21:09:42.932Z,1552597782.932 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-03-14T21:09:42.932Z,1552597782.932 [DUSBL:A.Pitch] Running Loop=1
2019-03-14T21:09:42.932Z,1552597782.932 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:B.SetSpeed] Running Loop=1
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:C] Running Loop=1
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:RequestRepeater] Running Loop=1
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:09:42.933Z,1552597782.933 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:09:42.934Z,1552597782.934 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:09:42.942Z,1552597782.942 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:09:42.943Z,1552597782.943 [DUSBL:C] Running Loop=1
2019-03-14T21:09:42.943Z,1552597782.943 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense DUSBL_Hydroid.range
2019-03-14T21:09:42.944Z,1552597782.944 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense DUSBL_Hydroid.direction
2019-03-14T21:09:42.944Z,1552597782.944 [DUSBL:B.SetSpeed] Running Loop=1
2019-03-14T21:09:42.944Z,1552597782.944 [DUSBL:A.Pitch] Running Loop=1
2019-03-14T21:09:44.468Z,1552597784.468 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:09:44.469Z,1552597784.469 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:09:44.470Z,1552597784.470 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:44.470Z,1552597784.470 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:44.471Z,1552597784.471 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:44.874Z,1552597784.874 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CADQF,19,*5C

2019-03-14T21:09:45.287Z,1552597785.287 [Micromodem](ERROR): Response from modem failed NMEA checksum: CAMS,BADCC,*2

2019-03-14T21:09:45.293Z,1552597785.293 [Micromodem](ERROR): Response from modem failed NMEA checksum: $AC6,1,20190314210944.316824,06,208,17,0090,0150,246,00,00,01,02,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,194,0.05,-999,9760,4000*53

2019-03-14T21:09:48.516Z,1552597788.516 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:09:48.517Z,1552597788.517 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:09:48.520Z,1552597788.520 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:48.520Z,1552597788.520 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:48.521Z,1552597788.521 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:49.004Z,1552597789.004 [Reporter](INFO): DUSBL_Hydroid.range -74930.820312 m
2019-03-14T21:09:49.004Z,1552597789.004 [Reporter](INFO): DUSBL_Hydroid.xAngle 58.450000 arcdeg
2019-03-14T21:09:50.145Z,1552597790.145 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:09:50.145Z,1552597790.145 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-03-14T21:09:50.145Z,1552597790.145 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-14T21:09:50.148Z,1552597790.148 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:09:50.148Z,1552597790.148 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-03-14T21:09:50.148Z,1552597790.148 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-14T21:09:50.149Z,1552597790.149 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:09:50.150Z,1552597790.150 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-03-14T21:09:50.150Z,1552597790.150 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-14T21:09:50.169Z,1552597790.169 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-14T21:09:50.169Z,1552597790.169 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-14T21:09:50.170Z,1552597790.170 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-14T21:09:50.591Z,1552597790.591 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-14T21:09:50.591Z,1552597790.591 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-03-14T21:09:50.592Z,1552597790.592 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-14T21:09:50.592Z,1552597790.592 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-03-14T21:09:50.592Z,1552597790.592 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-14T21:09:50.592Z,1552597790.592 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-03-14T21:09:51.085Z,1552597791.085 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-14T21:09:52.548Z,1552597792.548 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:09:52.550Z,1552597792.550 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:09:52.552Z,1552597792.552 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:52.553Z,1552597792.553 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:52.553Z,1552597792.553 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:52.981Z,1552597792.981 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:09:52.981Z,1552597792.981 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:09:52.981Z,1552597792.981 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:09:52.986Z,1552597792.986 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:09:52.986Z,1552597792.986 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:09:52.986Z,1552597792.986 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater] Running Loop=2
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:09:52.987Z,1552597792.987 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:09:53.862Z,1552597793.862 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20190314T210538/Courier0000.lzma
2019-03-14T21:09:54.668Z,1552597794.668 [DataOverHttps](INFO): Moved sent file to Logs/20190314T210538/Courier0000.lzma.bak
2019-03-14T21:09:54.668Z,1552597794.668 [DataOverHttps](INFO): SBD MOMSN=10139735
2019-03-14T21:09:56.587Z,1552597796.587 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:09:56.588Z,1552597796.588 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:09:56.589Z,1552597796.589 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:56.589Z,1552597796.589 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:09:56.589Z,1552597796.589 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:00.632Z,1552597800.632 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:00.634Z,1552597800.634 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:00.637Z,1552597800.637 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:00.637Z,1552597800.637 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:00.637Z,1552597800.637 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:03.551Z,1552597803.551 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:10:03.551Z,1552597803.551 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:10:03.551Z,1552597803.551 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater] Running Loop=3
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:10:03.552Z,1552597803.552 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:10:03.553Z,1552597803.553 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:10:03.861Z,1552597803.861 [NAL9602](INFO): Powering down
2019-03-14T21:10:04.668Z,1552597804.668 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:04.668Z,1552597804.668 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:04.669Z,1552597804.669 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:04.669Z,1552597804.669 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:04.669Z,1552597804.669 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:08.712Z,1552597808.712 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:08.717Z,1552597808.717 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:08.717Z,1552597808.717 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:08.717Z,1552597808.717 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:08.717Z,1552597808.717 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:12.747Z,1552597812.747 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:12.748Z,1552597812.748 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:12.748Z,1552597812.748 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:12.749Z,1552597812.749 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:12.749Z,1552597812.749 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:13.989Z,1552597813.989 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:10:13.989Z,1552597813.989 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:10:13.989Z,1552597813.989 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:10:13.993Z,1552597813.993 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:10:13.993Z,1552597813.993 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:10:13.993Z,1552597813.993 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:10:13.993Z,1552597813.993 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:10:13.993Z,1552597813.993 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:10:13.993Z,1552597813.993 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-03-14T21:10:13.994Z,1552597813.994 [DUSBL:RequestRepeater] Running Loop=4
2019-03-14T21:10:13.994Z,1552597813.994 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:10:13.994Z,1552597813.994 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:10:13.994Z,1552597813.994 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:10:13.994Z,1552597813.994 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:10:13.994Z,1552597813.994 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:10:16.788Z,1552597816.788 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:16.790Z,1552597816.790 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:16.793Z,1552597816.793 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:16.793Z,1552597816.793 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:16.793Z,1552597816.793 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:20.828Z,1552597820.828 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:20.833Z,1552597820.833 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:20.833Z,1552597820.833 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:20.833Z,1552597820.833 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:20.833Z,1552597820.833 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:24.502Z,1552597824.502 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:10:24.506Z,1552597824.506 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:10:24.506Z,1552597824.506 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:10:24.507Z,1552597824.507 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:10:24.507Z,1552597824.507 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:10:24.507Z,1552597824.507 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:10:24.507Z,1552597824.507 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:10:24.507Z,1552597824.507 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:10:24.507Z,1552597824.507 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-03-14T21:10:24.507Z,1552597824.507 [DUSBL:RequestRepeater] Running Loop=5
2019-03-14T21:10:24.508Z,1552597824.508 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:10:24.508Z,1552597824.508 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:10:24.508Z,1552597824.508 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:10:24.508Z,1552597824.508 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:10:24.508Z,1552597824.508 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:10:24.867Z,1552597824.867 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:24.868Z,1552597824.868 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:24.868Z,1552597824.868 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:24.869Z,1552597824.869 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:24.869Z,1552597824.869 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:28.908Z,1552597828.908 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:28.909Z,1552597828.909 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:28.909Z,1552597828.909 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:28.909Z,1552597828.909 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:28.910Z,1552597828.910 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:29.318Z,1552597829.318 [Micromodem](ERROR): Response from modem unexpected: $CACST,6,1,20190314211028.127280,06,557,15,0090,0150,246,00,00,02,02,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,197,-0.10,-999,9760,4000*73

2019-03-14T21:10:32.948Z,1552597832.948 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:32.952Z,1552597832.952 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:32.953Z,1552597832.953 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:32.953Z,1552597832.953 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:32.953Z,1552597832.953 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:34.997Z,1552597834.997 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:10:34.997Z,1552597834.997 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:10:34.997Z,1552597834.997 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:10:34.998Z,1552597834.998 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:10:34.998Z,1552597834.998 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:10:34.998Z,1552597834.998 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:10:34.998Z,1552597834.998 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:10:34.998Z,1552597834.998 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:10:34.998Z,1552597834.998 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-03-14T21:10:34.999Z,1552597834.999 [DUSBL:RequestRepeater] Running Loop=6
2019-03-14T21:10:34.999Z,1552597834.999 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:10:34.999Z,1552597834.999 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:10:34.999Z,1552597834.999 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:10:34.999Z,1552597834.999 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:10:34.999Z,1552597834.999 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:10:36.988Z,1552597836.988 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:36.990Z,1552597836.990 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:36.992Z,1552597836.992 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:36.993Z,1552597836.993 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:36.993Z,1552597836.993 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:41.033Z,1552597841.033 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:41.035Z,1552597841.035 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:41.037Z,1552597841.037 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:41.037Z,1552597841.037 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:41.037Z,1552597841.037 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:45.076Z,1552597845.076 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:45.081Z,1552597845.081 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:45.082Z,1552597845.082 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:45.082Z,1552597845.082 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:45.082Z,1552597845.082 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:45.537Z,1552597845.537 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:10:45.537Z,1552597845.537 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:10:45.537Z,1552597845.537 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:10:45.538Z,1552597845.538 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:10:45.538Z,1552597845.538 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:10:45.538Z,1552597845.538 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:10:45.538Z,1552597845.538 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:10:45.538Z,1552597845.538 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:10:45.538Z,1552597845.538 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-03-14T21:10:45.539Z,1552597845.539 [DUSBL:RequestRepeater] Running Loop=7
2019-03-14T21:10:45.539Z,1552597845.539 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:10:45.539Z,1552597845.539 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:10:45.539Z,1552597845.539 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:10:45.539Z,1552597845.539 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:10:45.539Z,1552597845.539 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:10:49.110Z,1552597849.110 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:49.112Z,1552597849.112 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:49.114Z,1552597849.114 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:49.114Z,1552597849.114 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:49.114Z,1552597849.114 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:53.155Z,1552597853.155 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:53.158Z,1552597853.158 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:53.160Z,1552597853.160 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:53.161Z,1552597853.161 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:53.161Z,1552597853.161 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:56.008Z,1552597856.008 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:10:56.009Z,1552597856.009 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:10:56.009Z,1552597856.009 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:10:56.009Z,1552597856.009 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:10:56.010Z,1552597856.010 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:10:56.010Z,1552597856.010 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:10:56.010Z,1552597856.010 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:10:56.010Z,1552597856.010 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:10:56.010Z,1552597856.010 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-03-14T21:10:56.010Z,1552597856.010 [DUSBL:RequestRepeater] Running Loop=8
2019-03-14T21:10:56.010Z,1552597856.010 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:10:56.011Z,1552597856.011 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:10:56.011Z,1552597856.011 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:10:56.011Z,1552597856.011 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:10:56.011Z,1552597856.011 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:10:57.192Z,1552597857.192 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:10:57.197Z,1552597857.197 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:10:57.198Z,1552597857.198 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:57.198Z,1552597857.198 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:10:57.198Z,1552597857.198 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:01.227Z,1552597861.227 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:11:01.228Z,1552597861.228 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:11:01.229Z,1552597861.229 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:01.229Z,1552597861.229 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:01.229Z,1552597861.229 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:05.268Z,1552597865.268 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:11:05.270Z,1552597865.270 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:11:05.273Z,1552597865.273 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:05.273Z,1552597865.273 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:05.273Z,1552597865.273 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:06.520Z,1552597866.520 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:11:06.520Z,1552597866.520 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:11:06.520Z,1552597866.520 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:11:06.521Z,1552597866.521 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:11:06.521Z,1552597866.521 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:11:06.521Z,1552597866.521 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:11:06.521Z,1552597866.521 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:11:06.521Z,1552597866.521 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:11:06.522Z,1552597866.522 [DUSBL:RequestRepeater](INFO): Running loop #9
2019-03-14T21:11:06.522Z,1552597866.522 [DUSBL:RequestRepeater] Running Loop=9
2019-03-14T21:11:06.522Z,1552597866.522 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:11:06.522Z,1552597866.522 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:11:06.522Z,1552597866.522 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:11:06.522Z,1552597866.522 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:11:06.522Z,1552597866.522 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:11:09.308Z,1552597869.308 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:11:09.313Z,1552597869.313 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:11:09.313Z,1552597869.313 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:09.313Z,1552597869.313 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:09.313Z,1552597869.313 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:13.348Z,1552597873.348 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:11:13.350Z,1552597873.350 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:11:13.352Z,1552597873.352 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:13.353Z,1552597873.353 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:13.353Z,1552597873.353 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:17.017Z,1552597877.017 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:11:17.017Z,1552597877.017 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:11:17.017Z,1552597877.017 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:11:17.018Z,1552597877.018 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:11:17.018Z,1552597877.018 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:11:17.018Z,1552597877.018 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:11:17.018Z,1552597877.018 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:11:17.018Z,1552597877.018 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:11:17.018Z,1552597877.018 [DUSBL:RequestRepeater](INFO): Running loop #10
2019-03-14T21:11:17.019Z,1552597877.019 [DUSBL:RequestRepeater] Running Loop=10
2019-03-14T21:11:17.019Z,1552597877.019 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-14T21:11:17.019Z,1552597877.019 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-14T21:11:17.019Z,1552597877.019 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-14T21:11:17.019Z,1552597877.019 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-14T21:11:17.019Z,1552597877.019 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:11:17.388Z,1552597877.388 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:11:17.388Z,1552597877.388 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:11:17.389Z,1552597877.389 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:17.389Z,1552597877.389 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:17.389Z,1552597877.389 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:21.432Z,1552597881.432 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:11:21.437Z,1552597881.437 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:11:21.437Z,1552597881.437 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:21.438Z,1552597881.438 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:21.438Z,1552597881.438 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:21.914Z,1552597881.914 [Reporter](INFO): DUSBL_Hydroid.range -74958.242188 m
2019-03-14T21:11:21.915Z,1552597881.915 [Reporter](INFO): DUSBL_Hydroid.xAngle -48.200000 arcdeg
2019-03-14T21:11:25.464Z,1552597885.464 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-14T21:11:25.465Z,1552597885.465 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-14T21:11:25.465Z,1552597885.465 [Micromodem](DEBUG): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:25.465Z,1552597885.465 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:25.466Z,1552597885.466 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-03-14T21:11:25.875Z,1552597885.875 [Micromodem](ERROR): Response from modem unexpected: $CADQF,191,1*59

2019-03-14T21:11:26.276Z,1552597886.276 [Micromodem](ERROR): Response from modem unexpected: $CAMSG,BAD_CRC,0*21

2019-03-14T21:11:27.566Z,1552597887.566 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-14T21:11:27.566Z,1552597887.566 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-14T21:11:27.566Z,1552597887.566 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:11:27.571Z,1552597887.571 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-14T21:11:27.571Z,1552597887.571 [DUSBL:RequestRepeater] Stopped
2019-03-14T21:11:27.571Z,1552597887.571 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-14T21:11:27.571Z,1552597887.571 [DUSBL:RequestRepeater:A] Stopped
2019-03-14T21:11:27.571Z,1552597887.571 [DUSBL:RequestRepeater:B] Stopped
2019-03-14T21:11:27.572Z,1552597887.572 [DUSBL](INFO): Completed DUSBL
2019-03-14T21:11:27.572Z,1552597887.572 [MissionManager](INFO): DUSBL is completed.
2019-03-14T21:11:27.572Z,1552597887.572 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-03-14T21:11:27.572Z,1552597887.572 [DUSBL] Stopped
2019-03-14T21:11:27.572Z,1552597887.572 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-03-14T21:11:27.572Z,1552597887.572 [DUSBL:A.Pitch] Stopped
2019-03-14T21:11:27.572Z,1552597887.572 [DUSBL:B.SetSpeed] Stopped
2019-03-14T21:11:27.572Z,1552597887.572 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-03-14T21:11:27.572Z,1552597887.572 [DUSBL:C] Stopped
2019-03-14T21:11:27.921Z,1552597887.921 [MissionManager](IMPORTANT): Started mission Default
2019-03-14T21:11:27.921Z,1552597887.921 [Default] Running Loop=1
2019-03-14T21:11:27.921Z,1552597887.921 [Default](DEBUG): Aggregate::initialize Default
2019-03-14T21:11:27.921Z,1552597887.921 [Default:B.GoToSurface] Running Loop=1
2019-03-14T21:11:27.921Z,1552597887.921 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-14T21:11:27.922Z,1552597887.922 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-14T21:11:27.922Z,1552597887.922 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-14T21:11:27.922Z,1552597887.922 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-14T21:11:27.923Z,1552597887.923 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-14T21:11:27.923Z,1552597887.923 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-14T21:11:27.923Z,1552597887.923 [Default:A.Wait] Running Loop=1
2019-03-14T21:11:27.923Z,1552597887.923 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:11:41.297Z,1552597901.297 [Default:A.Wait](INFO): Done Waiting.
2019-03-14T21:11:41.297Z,1552597901.297 [Default:A.Wait] Stopped
2019-03-14T21:11:41.297Z,1552597901.297 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:11:41.657Z,1552597901.657 [Default:CheckIn] Running Loop=1
2019-03-14T21:11:41.658Z,1552597901.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-03-14T21:11:41.658Z,1552597901.658 [Default:CheckIn:Read_GPS] Running Loop=1
2019-03-14T21:11:42.433Z,1552597902.433 [NAL9602](INFO): Powering up
2019-03-14T21:11:51.373Z,1552597911.373 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:11:51.373Z,1552597911.373 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-03-14T21:11:51.373Z,1552597911.373 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-14T21:11:51.375Z,1552597911.375 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:11:51.376Z,1552597911.376 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2019-03-14T21:11:51.376Z,1552597911.376 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-14T21:11:51.377Z,1552597911.377 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:11:51.377Z,1552597911.377 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2019-03-14T21:11:51.378Z,1552597911.378 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-14T21:11:51.409Z,1552597911.409 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-14T21:11:51.409Z,1552597911.409 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-14T21:11:51.409Z,1552597911.409 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-14T21:11:51.820Z,1552597911.820 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-14T21:11:51.820Z,1552597911.820 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-03-14T21:11:51.820Z,1552597911.820 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-14T21:11:51.820Z,1552597911.820 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2019-03-14T21:11:51.821Z,1552597911.821 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-14T21:11:51.821Z,1552597911.821 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2019-03-14T21:11:52.165Z,1552597912.165 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-14T21:11:53.346Z,1552597913.346 [NAL9602](INFO): NAL9602 initialized
2019-03-14T21:11:54.174Z,1552597914.174 [NAL9602](DEBUG): Fix Requested
2019-03-14T21:12:11.543Z,1552597931.543 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2019-03-14T21:13:06.624Z,1552597986.624 [CommandLine](IMPORTANT): got command show variable turnAroudn
2019-03-14T21:13:10.272Z,1552597990.272 [CommandLine](IMPORTANT): got command show variable turnaround
2019-03-14T21:13:10.372Z,1552597990.372 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (millisecond)
2019-03-14T21:13:12.956Z,1552597992.956 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-03-14T21:13:20.814Z,1552598000.814 [CommandLine](IMPORTANT): got command get DUSBL_Hydroid.defaultTurnAroundTime
2019-03-14T21:13:20.815Z,1552598000.815 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime 50.000000 ms
2019-03-14T21:13:52.191Z,1552598032.191 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:13:52.191Z,1552598032.191 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-03-14T21:13:52.191Z,1552598032.191 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-14T21:13:52.199Z,1552598032.199 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:13:52.199Z,1552598032.199 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2019-03-14T21:13:52.199Z,1552598032.199 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-14T21:13:52.201Z,1552598032.201 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:13:52.201Z,1552598032.201 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 3
2019-03-14T21:13:52.201Z,1552598032.201 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-14T21:13:52.233Z,1552598032.233 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-14T21:13:52.233Z,1552598032.233 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-14T21:13:52.233Z,1552598032.233 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-14T21:13:52.576Z,1552598032.576 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-14T21:13:52.576Z,1552598032.576 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-03-14T21:13:52.577Z,1552598032.577 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-14T21:13:52.577Z,1552598032.577 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2019-03-14T21:13:52.577Z,1552598032.577 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-14T21:13:52.577Z,1552598032.577 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 3
2019-03-14T21:13:52.969Z,1552598032.969 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-14T21:15:53.349Z,1552598153.349 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:15:53.349Z,1552598153.349 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-03-14T21:15:53.349Z,1552598153.349 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-14T21:15:53.352Z,1552598153.352 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:15:53.352Z,1552598153.352 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2019-03-14T21:15:53.352Z,1552598153.352 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-14T21:15:53.353Z,1552598153.353 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:15:53.354Z,1552598153.353 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 4
2019-03-14T21:15:53.354Z,1552598153.354 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-14T21:15:53.365Z,1552598153.365 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-14T21:15:53.365Z,1552598153.365 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-14T21:15:53.365Z,1552598153.365 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-14T21:15:53.763Z,1552598153.763 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-14T21:15:53.763Z,1552598153.763 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-03-14T21:15:53.764Z,1552598153.764 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-14T21:15:53.764Z,1552598153.764 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2019-03-14T21:15:53.765Z,1552598153.765 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-14T21:15:53.765Z,1552598153.765 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 4
2019-03-14T21:15:54.187Z,1552598154.187 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-14T21:16:41.838Z,1552598201.838 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-03-14T21:11:41.7Z
2019-03-14T21:16:41.838Z,1552598201.838 [Default:CheckIn:Read_GPS] Stopped
2019-03-14T21:16:41.838Z,1552598201.838 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-03-14T21:16:47.030Z,1552598207.030 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190314T210538/Courier0004.lzma
2019-03-14T21:16:47.923Z,1552598207.923 [DataOverHttps](INFO): Moved sent file to Logs/20190314T210538/Courier0004.lzma.bak
2019-03-14T21:16:47.924Z,1552598207.924 [DataOverHttps](INFO): SBD MOMSN=10139791
2019-03-14T21:16:51.568Z,1552598211.568 [RDI_Pathfinder](ERROR): Failed to parse:
:SA,   +0.00,   +0.00,  0.00
2019-03-14T21:16:55.961Z,1552598215.961 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-03-14T21:16:58.770Z,1552598218.770 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20190314T210538/Courier0007.lzma
2019-03-14T21:16:59.576Z,1552598219.576 [DataOverHttps](INFO): Moved sent file to Logs/20190314T210538/Courier0007.lzma.bak
2019-03-14T21:16:59.576Z,1552598219.576 [DataOverHttps](INFO): SBD MOMSN=10139796
2019-03-14T21:17:11.043Z,1552598231.043 [DataOverHttps](INFO): Sending 885 bytes from file Logs/20190314T204042/Express0011.lzma
2019-03-14T21:17:11.848Z,1552598231.848 [DataOverHttps](INFO): Moved sent file to Logs/20190314T204042/Express0011.lzma.bak
2019-03-14T21:17:11.848Z,1552598231.848 [DataOverHttps](INFO): SBD MOMSN=10139811
2019-03-14T21:17:23.304Z,1552598243.304 [DataOverHttps](INFO): Sending 1222 bytes from file Logs/20190314T210538/Express0001.lzma
2019-03-14T21:17:24.084Z,1552598244.084 [DataOverHttps](INFO): Moved sent file to Logs/20190314T210538/Express0001.lzma.bak
2019-03-14T21:17:24.084Z,1552598244.084 [DataOverHttps](INFO): SBD MOMSN=10139890
2019-03-14T21:17:26.664Z,1552598246.664 [NAL9602](INFO): Powering down
2019-03-14T21:17:35.287Z,1552598255.287 [DataOverHttps](INFO): Sending 702 bytes from file Logs/20190314T210538/Express0005.lzma
2019-03-14T21:17:36.092Z,1552598256.092 [DataOverHttps](INFO): Moved sent file to Logs/20190314T210538/Express0005.lzma.bak
2019-03-14T21:17:36.092Z,1552598256.092 [DataOverHttps](INFO): SBD MOMSN=10139928
2019-03-14T21:17:47.000Z,1552598267.000 [DataOverHttps](INFO): Sending 533 bytes from file Logs/20190314T210538/Express0008.lzma
2019-03-14T21:17:47.804Z,1552598267.804 [DataOverHttps](INFO): Moved sent file to Logs/20190314T210538/Express0008.lzma.bak
2019-03-14T21:17:47.804Z,1552598267.804 [DataOverHttps](INFO): SBD MOMSN=10139960
2019-03-14T21:17:48.929Z,1552598268.929 [Default:CheckIn:Read_Iridium] Stopped
2019-03-14T21:17:48.929Z,1552598268.929 [Default:CheckIn:C.Wait] Running Loop=1
2019-03-14T21:17:48.929Z,1552598268.929 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-03-14T21:17:54.566Z,1552598274.566 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:17:54.566Z,1552598274.566 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-03-14T21:17:54.566Z,1552598274.566 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-14T21:17:54.568Z,1552598274.568 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:17:54.568Z,1552598274.568 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2019-03-14T21:17:54.568Z,1552598274.568 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-14T21:17:54.570Z,1552598274.570 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-14T21:17:54.570Z,1552598274.570 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 5
2019-03-14T21:17:54.570Z,1552598274.570 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-14T21:17:54.581Z,1552598274.581 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-14T21:17:54.581Z,1552598274.581 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-14T21:17:54.582Z,1552598274.582 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-14T21:17:54.987Z,1552598274.987 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-14T21:17:54.987Z,1552598274.987 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-03-14T21:17:54.988Z,1552598274.988 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-14T21:17:54.988Z,1552598274.988 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2019-03-14T21:17:54.989Z,1552598274.989 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-14T21:17:54.989Z,1552598274.989 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 5
2019-03-14T21:17:55.385Z,1552598275.385 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-14T21:19:15.376Z,1552598355.376 [CommandLine](IMPORTANT): got command restart application
2019-03-14T21:19:16.382Z,1552598356.382 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-03-14T21:19:16.382Z,1552598356.382 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:16.383Z,1552598356.383 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.510Z,1552598356.510 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-03-14T21:19:16.510Z,1552598356.510 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.511Z,1552598356.511 [CommandLine](INFO): Join timeout helper Thread ID is 1222
2019-03-14T21:19:16.511Z,1552598356.511 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-03-14T21:19:16.511Z,1552598356.511 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.512Z,1552598356.512 [NavChartDb](INFO): Join timeout helper Thread ID is 1223
2019-03-14T21:19:16.722Z,1552598356.722 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:16.722Z,1552598356.722 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.730Z,1552598356.730 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-03-14T21:19:16.730Z,1552598356.730 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.731Z,1552598356.731 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1224
2019-03-14T21:19:16.738Z,1552598356.738 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:16.738Z,1552598356.738 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-03-14T21:19:16.739Z,1552598356.739 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.750Z,1552598356.750 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-03-14T21:19:16.750Z,1552598356.750 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.751Z,1552598356.751 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1225
2019-03-14T21:19:16.838Z,1552598356.838 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:16.839Z,1552598356.839 [CTD_NeilBrown](INFO): Powering down
2019-03-14T21:19:16.850Z,1552598356.850 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.851Z,1552598356.851 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-03-14T21:19:16.851Z,1552598356.851 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:16.851Z,1552598356.851 [Radio_Surface](INFO): Join timeout helper Thread ID is 1226
2019-03-14T21:19:17.166Z,1552598357.166 [Radio_Surface](INFO): Powering down
2019-03-14T21:19:17.167Z,1552598357.167 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:17.168Z,1552598357.168 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.175Z,1552598357.175 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-03-14T21:19:17.175Z,1552598357.175 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.176Z,1552598357.176 [DataOverHttps](INFO): Join timeout helper Thread ID is 1227
2019-03-14T21:19:17.211Z,1552598357.211 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:17.212Z,1552598357.212 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.216Z,1552598357.216 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-03-14T21:19:17.216Z,1552598357.216 [logger ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.217Z,1552598357.217 [logger](INFO): Join timeout helper Thread ID is 1228
2019-03-14T21:19:17.227Z,1552598357.227 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:17.227Z,1552598357.227 [logger ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.235Z,1552598357.235 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-03-14T21:19:17.235Z,1552598357.235 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.235Z,1552598357.235 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-03-14T21:19:17.235Z,1552598357.235 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.236Z,1552598357.236 [controlThread](INFO): Join timeout helper Thread ID is 1229
2019-03-14T21:19:17.362Z,1552598357.362 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-14T21:19:17.362Z,1552598357.362 [controlThread](DEBUG): Uninitializing ControlThread
2019-03-14T21:19:17.363Z,1552598357.363 [DUSBL_Hydroid](INFO): Powering down
2019-03-14T21:19:17.434Z,1552598357.434 [Micromodem](INFO): uninitialize
2019-03-14T21:19:17.435Z,1552598357.435 [Micromodem](INFO): Powering down
2019-03-14T21:19:17.530Z,1552598357.530 [NAL9602](INFO): Powering down
2019-03-14T21:19:17.602Z,1552598357.602 [RDI_Pathfinder](INFO): Powering down
2019-03-14T21:19:17.603Z,1552598357.603 [RDI_PathfinderUp](INFO): Powering down
2019-03-14T21:19:17.604Z,1552598357.604 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-03-14T21:19:17.605Z,1552598357.605 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-03-14T21:19:17.606Z,1552598357.606 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-03-14T21:19:17.607Z,1552598357.607 [MissionManager](INFO): Uninitializing Mission Default
2019-03-14T21:19:17.607Z,1552598357.607 [Default] Stopped
2019-03-14T21:19:17.607Z,1552598357.607 [Default](DEBUG): Aggregate::uninitialize Default
2019-03-14T21:19:17.607Z,1552598357.607 [Default:B.GoToSurface] Stopped
2019-03-14T21:19:17.607Z,1552598357.607 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-14T21:19:17.607Z,1552598357.607 [Default:CheckIn] Stopped
2019-03-14T21:19:17.607Z,1552598357.607 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-03-14T21:19:17.607Z,1552598357.607 [Default:CheckIn:C.Wait] Stopped
2019-03-14T21:19:17.607Z,1552598357.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-14T21:19:17.610Z,1552598357.610 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-03-14T21:19:17.610Z,1552598357.610 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-03-14T21:19:17.610Z,1552598357.610 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-03-14T21:19:17.611Z,1552598357.611 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-03-14T21:19:17.611Z,1552598357.611 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-03-14T21:19:17.611Z,1552598357.611 [BuoyancyServo](INFO): Powering down
2019-03-14T21:19:17.622Z,1552598357.622 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-03-14T21:19:17.622Z,1552598357.622 [ElevatorServo](INFO): Powering down
2019-03-14T21:19:17.623Z,1552598357.623 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-03-14T21:19:17.623Z,1552598357.623 [MassServo](INFO): Powering down
2019-03-14T21:19:17.624Z,1552598357.624 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-03-14T21:19:17.624Z,1552598357.624 [RudderServo](INFO): Powering down
2019-03-14T21:19:17.625Z,1552598357.625 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-03-14T21:19:17.625Z,1552598357.625 [ThrusterServo](INFO): Powering down
2019-03-14T21:19:17.626Z,1552598357.626 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-03-14T21:19:17.626Z,1552598357.626 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-03-14T21:19:17.627Z,1552598357.627 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-03-14T21:19:17.627Z,1552598357.627 [CBIT](DEBUG): Powering off loads.
2019-03-14T21:19:17.638Z,1552598357.638 [CBIT](DEBUG): Disabling WDT.
2019-03-14T21:19:17.650Z,1552598357.650 [CBIT](DEBUG): Opening all GF detection circuits.
2019-03-14T21:19:17.651Z,1552598357.651 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.703Z,1552598357.703 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.712Z,1552598357.712 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.755Z,1552598357.755 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.757Z,1552598357.757 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.810Z,1552598357.810 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-14T21:19:17.881Z,1552598357.881 [logger ThreadHandler](INFO): Thread cancelled.