2019-07-09T17:02:38.891Z,1562691758.891 [Supervisor](DEBUG): Initializing supervisor.
2019-07-09T17:02:38.895Z,1562691758.895 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-07-09T17:02:38.895Z,1562691758.895 [SyncHandler](INFO): Protected caller Thread ID is 5059
2019-07-09T17:02:38.896Z,1562691758.896 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-07-09T17:02:38.897Z,1562691758.897 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-07-09T17:02:38.897Z,1562691758.897 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5060
2019-07-09T17:02:38.900Z,1562691758.900 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-07-09T17:02:38.912Z,1562691758.912 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-07-09T17:02:38.913Z,1562691758.913 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-07-09T17:02:38.914Z,1562691758.914 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5061
2019-07-09T17:02:38.914Z,1562691758.914 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-07-09T17:02:38.915Z,1562691758.915 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-07-09T17:02:38.916Z,1562691758.916 [logger ThreadHandler](INFO): Protected caller Thread ID is 5062
2019-07-09T17:02:38.918Z,1562691758.918 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-07-09T17:02:38.918Z,1562691758.918 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-07-09T17:02:38.920Z,1562691758.920 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-07-09T17:02:39.377Z,1562691759.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-07-09T17:02:39.378Z,1562691759.378 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-07-09T17:02:39.475Z,1562691759.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-07-09T17:02:39.476Z,1562691759.476 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-07-09T17:02:39.784Z,1562691759.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-07-09T17:02:39.785Z,1562691759.785 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-07-09T17:02:39.923Z,1562691759.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-07-09T17:02:39.924Z,1562691759.924 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-07-09T17:02:40.113Z,1562691760.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-07-09T17:02:40.113Z,1562691760.113 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-07-09T17:02:40.550Z,1562691760.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-07-09T17:02:40.551Z,1562691760.551 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-07-09T17:02:40.754Z,1562691760.754 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-07-09T17:02:40.755Z,1562691760.755 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-07-09T17:02:40.897Z,1562691760.897 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-07-09T17:02:40.898Z,1562691760.898 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-07-09T17:02:41.087Z,1562691761.087 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-07-09T17:02:41.087Z,1562691761.087 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-07-09T17:02:41.183Z,1562691761.183 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-07-09T17:02:41.183Z,1562691761.183 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-07-09T17:02:41.476Z,1562691761.476 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-07-09T17:02:41.477Z,1562691761.477 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-07-09T17:02:41.558Z,1562691761.558 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-07-09T17:02:41.660Z,1562691761.660 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-07-09T17:02:41.661Z,1562691761.661 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-07-09T17:02:42.237Z,1562691762.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-07-09T17:02:42.238Z,1562691762.238 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-07-09T17:02:42.622Z,1562691762.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-07-09T17:02:42.624Z,1562691762.624 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-07-09T17:02:42.625Z,1562691762.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-07-09T17:02:42.830Z,1562691762.830 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-07-09T17:02:42.931Z,1562691762.931 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-07-09T17:02:43.029Z,1562691763.029 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-07-09T17:02:43.403Z,1562691763.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-07-09T17:02:43.404Z,1562691763.404 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-07-09T17:02:43.644Z,1562691763.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-07-09T17:02:43.804Z,1562691763.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-07-09T17:02:43.900Z,1562691763.900 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-07-09T17:02:43.983Z,1562691763.983 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-07-09T17:02:44.090Z,1562691764.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-07-09T17:02:44.265Z,1562691764.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-07-09T17:02:44.394Z,1562691764.394 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-07-09T17:02:44.395Z,1562691764.395 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-07-09T17:02:44.398Z,1562691764.398 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-07-09T17:02:44.792Z,1562691764.792 [AHRS_M2] Loaded
2019-07-09T17:02:44.792Z,1562691764.792 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-07-09T17:02:44.868Z,1562691764.868 [DataOverHttps] Loaded
2019-07-09T17:02:44.869Z,1562691764.869 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-07-09T17:02:44.870Z,1562691764.870 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407654E0
2019-07-09T17:02:44.870Z,1562691764.870 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5141
2019-07-09T17:02:44.883Z,1562691764.883 [Depth_Keller] Loaded
2019-07-09T17:02:44.884Z,1562691764.884 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-07-09T17:02:44.942Z,1562691764.942 [DUSBL_Hydroid] Loaded
2019-07-09T17:02:44.942Z,1562691764.942 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-07-09T17:02:44.991Z,1562691764.991 [Micromodem] Loaded
2019-07-09T17:02:44.992Z,1562691764.992 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-07-09T17:02:45.090Z,1562691765.090 [NAL9602] Loaded
2019-07-09T17:02:45.091Z,1562691765.091 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-07-09T17:02:45.106Z,1562691765.106 [Onboard] Loaded
2019-07-09T17:02:45.107Z,1562691765.107 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-07-09T17:02:45.113Z,1562691765.113 [PowerOnly] Loaded
2019-07-09T17:02:45.113Z,1562691765.113 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-07-09T17:02:45.120Z,1562691765.120 [Radio_Surface] Loaded
2019-07-09T17:02:45.120Z,1562691765.120 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-07-09T17:02:45.121Z,1562691765.121 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407954E0
2019-07-09T17:02:45.122Z,1562691765.122 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5142
2019-07-09T17:02:45.166Z,1562691765.166 [RDI_Pathfinder] Loaded
2019-07-09T17:02:45.166Z,1562691765.166 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-07-09T17:02:46.645Z,1562691766.645 [BPC1] Loaded
2019-07-09T17:02:46.645Z,1562691766.645 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-07-09T17:02:46.645Z,1562691766.645 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-07-09T17:02:46.646Z,1562691766.646 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-07-09T17:02:46.659Z,1562691766.659 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-07-09T17:02:46.660Z,1562691766.660 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-07-09T17:02:46.768Z,1562691766.768 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-07-09T17:02:46.768Z,1562691766.768 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-07-09T17:02:46.790Z,1562691766.790 [NavChart] Loaded
2019-07-09T17:02:46.790Z,1562691766.790 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-07-09T17:02:46.794Z,1562691766.794 [UniversalFixResidualReporter] Loaded
2019-07-09T17:02:46.794Z,1562691766.794 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-07-09T17:02:46.795Z,1562691766.795 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-07-09T17:02:46.795Z,1562691766.795 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-07-09T17:02:46.901Z,1562691766.901 [BuoyancyServo] Loaded
2019-07-09T17:02:46.901Z,1562691766.901 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-07-09T17:02:46.917Z,1562691766.917 [ElevatorServo] Loaded
2019-07-09T17:02:46.917Z,1562691766.917 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-07-09T17:02:46.932Z,1562691766.932 [MassServo] Loaded
2019-07-09T17:02:46.932Z,1562691766.932 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-07-09T17:02:46.948Z,1562691766.948 [RudderServo] Loaded
2019-07-09T17:02:46.948Z,1562691766.948 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-07-09T17:02:46.963Z,1562691766.963 [ThrusterServo] Loaded
2019-07-09T17:02:46.963Z,1562691766.963 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-07-09T17:02:46.963Z,1562691766.963 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-07-09T17:02:46.964Z,1562691766.964 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-07-09T17:02:47.212Z,1562691767.212 [CTD_NeilBrown] Loaded
2019-07-09T17:02:47.213Z,1562691767.213 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-07-09T17:02:47.214Z,1562691767.214 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E04E0
2019-07-09T17:02:47.214Z,1562691767.214 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 5143
2019-07-09T17:02:47.260Z,1562691767.260 [WetLabsSeaOWL_UV_A] Loaded
2019-07-09T17:02:47.260Z,1562691767.260 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-07-09T17:02:47.261Z,1562691767.261 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409104E0
2019-07-09T17:02:47.261Z,1562691767.261 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 5144
2019-07-09T17:02:47.262Z,1562691767.262 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-07-09T17:02:47.262Z,1562691767.262 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-07-09T17:02:47.554Z,1562691767.554 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-07-09T17:02:47.555Z,1562691767.555 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-07-09T17:02:47.597Z,1562691767.597 [DepthRateCalculator] Loaded
2019-07-09T17:02:47.597Z,1562691767.597 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-07-09T17:02:47.603Z,1562691767.603 [PitchRateCalculator] Loaded
2019-07-09T17:02:47.603Z,1562691767.603 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-07-09T17:02:47.616Z,1562691767.616 [SpeedCalculator] Loaded
2019-07-09T17:02:47.616Z,1562691767.616 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-07-09T17:02:47.637Z,1562691767.638 [TempGradientCalculator] Loaded
2019-07-09T17:02:47.638Z,1562691767.638 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-07-09T17:02:47.643Z,1562691767.643 [YawRateCalculator] Loaded
2019-07-09T17:02:47.644Z,1562691767.644 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-07-09T17:02:47.686Z,1562691767.686 [ElevatorOffsetCalculator] Loaded
2019-07-09T17:02:47.686Z,1562691767.686 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-07-09T17:02:47.686Z,1562691767.686 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-07-09T17:02:47.687Z,1562691767.687 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-07-09T17:02:47.822Z,1562691767.822 [SBIT](DEBUG): Construct Startup Built In Test.
2019-07-09T17:02:47.844Z,1562691767.844 [SBIT] Loaded
2019-07-09T17:02:47.845Z,1562691767.845 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-07-09T17:02:47.845Z,1562691767.845 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-07-09T17:02:47.857Z,1562691767.857 [IBIT] Loaded
2019-07-09T17:02:47.857Z,1562691767.857 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-07-09T17:02:47.860Z,1562691767.860 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-07-09T17:02:48.038Z,1562691768.038 [CBIT] Loaded
2019-07-09T17:02:48.038Z,1562691768.038 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-07-09T17:02:48.039Z,1562691768.039 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-07-09T17:02:48.039Z,1562691768.039 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-07-09T17:02:48.118Z,1562691768.118 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-07-09T17:02:48.119Z,1562691768.119 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-07-09T17:02:48.214Z,1562691768.214 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-07-09T17:02:48.215Z,1562691768.215 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-07-09T17:02:48.281Z,1562691768.281 [VerticalControl](DEBUG): Construct VerticalControl.
2019-07-09T17:02:48.367Z,1562691768.367 [VerticalControl] Loaded
2019-07-09T17:02:48.368Z,1562691768.368 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-07-09T17:02:48.368Z,1562691768.368 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-07-09T17:02:48.427Z,1562691768.427 [HorizontalControl] Loaded
2019-07-09T17:02:48.427Z,1562691768.427 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-07-09T17:02:48.428Z,1562691768.428 [SpeedControl](DEBUG): Construct SpeedControl.
2019-07-09T17:02:48.429Z,1562691768.429 [SpeedControl] Loaded
2019-07-09T17:02:48.430Z,1562691768.430 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-07-09T17:02:48.430Z,1562691768.430 [LoopControl](DEBUG): Construct LoopControl.
2019-07-09T17:02:48.431Z,1562691768.431 [LoopControl] Loaded
2019-07-09T17:02:48.431Z,1562691768.431 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-07-09T17:02:48.432Z,1562691768.432 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-07-09T17:02:48.432Z,1562691768.432 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-07-09T17:02:48.543Z,1562691768.543 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-07-09T17:02:48.582Z,1562691768.582 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-07-09T17:02:48.583Z,1562691768.583 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-07-09T17:02:48.591Z,1562691768.591 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-07-09T17:02:48.592Z,1562691768.592 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2019-07-09T17:02:48.593Z,1562691768.593 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5145
2019-07-09T17:02:48.597Z,1562691768.597 [Supervisor](INFO): Main Thread ID is 4931
2019-07-09T17:02:48.597Z,1562691768.597 [Supervisor](DEBUG): Running supervisor.
2019-07-09T17:02:48.598Z,1562691768.598 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5146
2019-07-09T17:02:48.600Z,1562691768.600 [controlThread ThreadHandler](INFO): Handler Thread ID is 5147
2019-07-09T17:02:48.601Z,1562691768.601 [controlThread](DEBUG): Initializing ControlThread
2019-07-09T17:02:48.607Z,1562691768.607 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-07-09T17:02:48.608Z,1562691768.608 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-07-09T17:02:48.609Z,1562691768.609 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-07-09T17:02:48.610Z,1562691768.610 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-07-09T17:02:48.610Z,1562691768.610 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-07-09T17:02:48.610Z,1562691768.610 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-07-09T17:02:48.611Z,1562691768.611 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-07-09T17:02:48.611Z,1562691768.611 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-07-09T17:02:48.612Z,1562691768.612 [SBIT](INFO): Initialize SBIT Component.
2019-07-09T17:02:48.612Z,1562691768.612 [SBIT](IMPORTANT): git: 2019-07-01
2019-07-09T17:02:48.612Z,1562691768.612 [SBIT](INFO): git hash: 66ee1f914ed66d399bd38d45ccca9e12ca50b60d
2019-07-09T17:02:48.613Z,1562691768.613 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-07-09T17:02:48.614Z,1562691768.614 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-07-09T17:02:48.615Z,1562691768.615 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-07-09T17:02:48.615Z,1562691768.615 [IBIT](INFO): Initialize IBIT Component.
2019-07-09T17:02:48.616Z,1562691768.616 [CBIT](DEBUG): Initialize CBIT Component.
2019-07-09T17:02:48.617Z,1562691768.617 [logger ThreadHandler](INFO): Handler Thread ID is 5148
2019-07-09T17:02:48.629Z,1562691768.629 [CBIT](DEBUG): Initialized mux pins.
2019-07-09T17:02:48.629Z,1562691768.629 [CBIT](DEBUG): Initializing the watchdog timer.
2019-07-09T17:02:48.638Z,1562691768.638 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5149
2019-07-09T17:02:48.639Z,1562691768.639 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-07-09T17:02:48.649Z,1562691768.649 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5150
2019-07-09T17:02:48.653Z,1562691768.653 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-07-09T17:02:48.653Z,1562691768.653 [CBIT](DEBUG): Initializing heartbeat.
2019-07-09T17:02:48.669Z,1562691768.669 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 5151
2019-07-09T17:02:48.670Z,1562691768.670 [CTD_NeilBrown](INFO): Powering down
2019-07-09T17:02:48.697Z,1562691768.697 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 5152
2019-07-09T17:02:48.698Z,1562691768.698 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-07-09T17:02:48.725Z,1562691768.725 [CBIT](DEBUG): Deactivating GF circuits.
2019-07-09T17:02:48.725Z,1562691768.725 [CBIT](DEBUG): Deactivating emergency mode.
2019-07-09T17:02:48.729Z,1562691768.729 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5153
2019-07-09T17:02:48.733Z,1562691768.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-07-09T17:02:48.733Z,1562691768.733 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-07-09T17:02:48.733Z,1562691768.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-07-09T17:02:48.733Z,1562691768.733 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-07-09T17:02:48.733Z,1562691768.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-07-09T17:02:48.733Z,1562691768.733 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-07-09T17:02:48.734Z,1562691768.734 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-07-09T17:02:48.734Z,1562691768.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-07-09T17:02:48.734Z,1562691768.734 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-07-09T17:02:48.734Z,1562691768.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-07-09T17:02:48.734Z,1562691768.734 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-07-09T17:02:48.734Z,1562691768.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-07-09T17:02:48.735Z,1562691768.735 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-07-09T17:02:48.735Z,1562691768.735 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-07-09T17:02:48.735Z,1562691768.735 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-07-09T17:02:48.735Z,1562691768.735 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-07-09T17:02:48.761Z,1562691768.761 [CBIT](DEBUG): Backplane powered.
2019-07-09T17:02:48.761Z,1562691768.761 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-07-09T17:02:48.763Z,1562691768.763 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-07-09T17:02:48.763Z,1562691768.763 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-07-09T17:02:48.764Z,1562691768.764 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-07-09T17:02:48.765Z,1562691768.765 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-07-09T17:02:48.776Z,1562691768.776 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-09T17:02:48.799Z,1562691768.799 [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-07-09T17:02:48.800Z,1562691768.800 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-07-09T17:02:48.886Z,1562691768.886 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-07-09T17:02:48.887Z,1562691768.887 [Default:A.Wait](DEBUG): Construct Wait.
2019-07-09T17:02:48.889Z,1562691768.889 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-09T17:02:48.919Z,1562691768.919 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-07-09T17:02:48.938Z,1562691768.938 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-07-09T17:02:48.943Z,1562691768.943 [Default:E.Execute](DEBUG): Construct Execute.
2019-07-09T17:02:48.955Z,1562691768.955 [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-07-09T17:02:48.976Z,1562691768.976 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-07-09T17:02:49.006Z,1562691769.006 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-07-09T17:02:49.045Z,1562691769.045 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-07-09T17:02:49.053Z,1562691769.053 [Radio_Surface](INFO): Powering up
2019-07-09T17:02:49.054Z,1562691769.054 [DUSBL_Hydroid](INFO): Powering up
2019-07-09T17:02:49.054Z,1562691769.054 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-07-09T17:02:49.138Z,1562691769.138 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-07-09T17:02:49.149Z,1562691769.149 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-07-09T17:02:49.157Z,1562691769.157 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-07-09T17:02:49.158Z,1562691769.158 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-07-09T17:02:49.165Z,1562691769.165 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-07-09T17:02:49.166Z,1562691769.166 [MassServo](DEBUG): Initializing EZServoServo.
2019-07-09T17:02:49.173Z,1562691769.173 [MassServo](DEBUG): Initializing MassServo.
2019-07-09T17:02:49.174Z,1562691769.174 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-09T17:02:49.181Z,1562691769.181 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-09T17:02:49.182Z,1562691769.182 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-07-09T17:02:49.189Z,1562691769.189 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-07-09T17:02:49.399Z,1562691769.399 [Micromodem](INFO): Powering up
2019-07-09T17:02:49.400Z,1562691769.400 [Micromodem](DEBUG): Initializing Micromodem.
2019-07-09T17:02:49.429Z,1562691769.429 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-07-09T17:02:50.129Z,1562691770.129 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-07-09T17:02:50.129Z,1562691770.129 [RudderServo](FAULT): Rudder failed to initialize
2019-07-09T17:02:50.129Z,1562691770.129 [RudderServo] Communications Fault, FailCount= 1
2019-07-09T17:02:50.129Z,1562691770.129 [RudderServo](ERROR): Communications Fault
2019-07-09T17:02:50.240Z,1562691770.240 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-07-09T17:02:50.422Z,1562691770.422 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-09T17:02:50.422Z,1562691770.422 [RudderServo](INFO): Powering down
2019-07-09T17:02:51.085Z,1562691771.085 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-09T17:02:51.206Z,1562691771.206 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-09T17:02:51.210Z,1562691771.210 [CBIT](INFO): Clearing failed state for component RudderServo
2019-07-09T17:02:51.210Z,1562691771.210 [RudderServo] No Fault, FailCount= 1
2019-07-09T17:02:54.328Z,1562691774.328 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-07-09T17:02:54.731Z,1562691774.731 [Micromodem](INFO): Nmea in: $CATMG,2019-07-09T17:02:53Z,RTC,RTC*78

2019-07-09T17:02:54.732Z,1562691774.732 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-07-09T17:02:53Z,RTC,RTC*78

2019-07-09T17:02:55.243Z,1562691775.243 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-07-09T17:02:55.243Z,1562691775.243 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-07-09T17:02:55.643Z,1562691775.643 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-07-09T17:02:55.643Z,1562691775.643 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-07-09T17:02:56.047Z,1562691776.047 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-07-09T17:02:56.047Z,1562691776.047 [Micromodem](INFO): Nmea out: $CCCFG,nav.nst,1*4D

2019-07-09T17:02:56.451Z,1562691776.451 [Micromodem](INFO): Nmea in: $CACFG,nav.nst,1*4F

2019-07-09T17:02:56.451Z,1562691776.451 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2019-07-09T17:02:56.855Z,1562691776.855 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2019-07-09T17:02:56.855Z,1562691776.855 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2019-07-09T17:02:57.262Z,1562691777.262 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2019-07-09T17:02:57.263Z,1562691777.263 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2019-07-09T17:02:57.655Z,1562691777.655 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2019-07-09T17:02:57.655Z,1562691777.655 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2019-07-09T17:02:58.048Z,1562691778.048 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2019-07-09T17:02:58.048Z,1562691778.048 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2019-07-09T17:02:58.455Z,1562691778.455 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2019-07-09T17:02:58.456Z,1562691778.456 [Micromodem](INFO): Nmea out: $CCCLK,2019,07,09,17,02,59*48

2019-07-09T17:02:58.872Z,1562691778.872 [Micromodem](INFO): Nmea in: $CACLK,2019,7,9,17,2,59*7A

2019-07-09T17:02:58.882Z,1562691778.882 [Micromodem](INFO): Nmea in: $CATMS,0,2019-07-09T17:03:00Z*77

2019-07-09T17:02:58.883Z,1562691778.883 [Micromodem](INFO): Nmea in: $CATMG,2019-07-09T17:03:00Z,USER_CMD,RTC*3E

2019-07-09T17:03:02.501Z,1562691782.501 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-07-09T17:03:06.922Z,1562691786.922 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-07-09T17:03:12.593Z,1562691792.593 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2019-07-09T17:03:15.407Z,1562691795.407 [NAL9602](INFO): Powering up NAL9602
2019-07-09T17:03:17.051Z,1562691797.051 [SBIT](IMPORTANT): Beginning Startup BIT
2019-07-09T17:03:17.059Z,1562691797.059 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-09T17:03:26.539Z,1562691806.539 [NAL9602](INFO): NAL9602 initialized
2019-07-09T17:03:27.373Z,1562691807.373 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:03:28.287Z,1562691808.287 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008685
CHAN A1 (24V): -0.027748
CHAN A2 (12V): -0.004693
CHAN A3 (5V): -0.002163
CHAN B0 (3.3V): -0.000072
CHAN B1 (3.15aV): -0.000120
CHAN B2 (3.15bV): 0.000416
CHAN B3 (GND): 0.002294
OPEN: 0.005573
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-09T17:04:03.607Z,1562691843.607 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-07-09T17:04:03.608Z,1562691843.608 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-07-09T17:04:10.483Z,1562691850.483 [SBIT](IMPORTANT): SBIT PASSED
2019-07-09T17:04:10.573Z,1562691850.573 [CommandLine](IMPORTANT): got command configSet list
2019-07-09T17:04:10.573Z,1562691850.573 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-09T17:04:10.574Z,1562691850.574 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-07-09T17:04:10.902Z,1562691850.902 [MissionManager](IMPORTANT): Started mission Startup
2019-07-09T17:04:10.902Z,1562691850.902 [Startup] Running Loop=1
2019-07-09T17:04:10.903Z,1562691850.903 [Startup](DEBUG): Aggregate::initialize Startup
2019-07-09T17:04:10.903Z,1562691850.903 [Startup:A.GoToSurface] Running Loop=1
2019-07-09T17:04:10.903Z,1562691850.903 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-09T17:04:10.903Z,1562691850.903 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-09T17:04:10.904Z,1562691850.904 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-09T17:04:10.904Z,1562691850.904 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-09T17:04:10.905Z,1562691850.905 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-09T17:04:10.905Z,1562691850.905 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-09T17:04:10.906Z,1562691850.906 [Startup:StartupSatComms] Running Loop=1
2019-07-09T17:04:10.906Z,1562691850.906 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-07-09T17:04:10.907Z,1562691850.907 [Startup:StartupSatComms:A] Running Loop=1
2019-07-09T17:04:11.302Z,1562691851.302 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-07-09T17:05:11.094Z,1562691911.094 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-09T17:04:10.9Z
2019-07-09T17:05:11.094Z,1562691911.094 [Startup:StartupSatComms:A] Stopped
2019-07-09T17:05:11.094Z,1562691911.094 [Startup:StartupSatComms:B] Running Loop=1
2019-07-09T17:05:11.482Z,1562691911.482 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-09T17:05:15.350Z,1562691915.350 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004646
2019-07-09T17:05:22.281Z,1562691922.281 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20190709T165912/Express0005.lzma
2019-07-09T17:05:23.643Z,1562691923.643 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-09T17:05:23.643Z,1562691923.643 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19070910142974,35.0, -0.1,   0.0  0
2019-07-09T17:05:24.551Z,1562691924.551 [DataOverHttps](INFO): Moved sent file to Logs/20190709T165912/Express0005.lzma.bak
2019-07-09T17:05:24.551Z,1562691924.551 [DataOverHttps](INFO): SBD MOMSN=11435875
2019-07-09T17:05:37.017Z,1562691937.017 [DataOverHttps](INFO): Sending 641 bytes from file Logs/20190709T170238/Express0001.lzma
2019-07-09T17:05:37.822Z,1562691937.822 [DataOverHttps](INFO): Moved sent file to Logs/20190709T170238/Express0001.lzma.bak
2019-07-09T17:05:37.822Z,1562691937.822 [DataOverHttps](INFO): SBD MOMSN=11435881
2019-07-09T17:05:40.182Z,1562691940.182 [Startup:StartupSatComms:B] Stopped
2019-07-09T17:05:40.182Z,1562691940.182 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-07-09T17:05:40.182Z,1562691940.182 [Startup:StartupSatComms] Stopped
2019-07-09T17:05:40.182Z,1562691940.182 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-07-09T17:05:40.183Z,1562691940.183 [Startup](INFO): Completed Startup
2019-07-09T17:05:40.183Z,1562691940.183 [MissionManager](INFO): Startup is completed.
2019-07-09T17:05:40.183Z,1562691940.183 [MissionManager](INFO): Uninitializing Mission Startup
2019-07-09T17:05:40.183Z,1562691940.183 [Startup] Stopped
2019-07-09T17:05:40.183Z,1562691940.183 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-07-09T17:05:40.184Z,1562691940.184 [Startup:A.GoToSurface] Stopped
2019-07-09T17:05:40.184Z,1562691940.184 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-09T17:05:40.635Z,1562691940.635 [MissionManager](IMPORTANT): Started mission Default
2019-07-09T17:05:40.635Z,1562691940.635 [Default] Running Loop=1
2019-07-09T17:05:40.635Z,1562691940.635 [Default](DEBUG): Aggregate::initialize Default
2019-07-09T17:05:40.635Z,1562691940.635 [Default:B.GoToSurface] Running Loop=1
2019-07-09T17:05:40.635Z,1562691940.635 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-09T17:05:40.635Z,1562691940.635 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-09T17:05:40.636Z,1562691940.636 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-09T17:05:40.636Z,1562691940.636 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-09T17:05:40.636Z,1562691940.636 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-09T17:05:40.641Z,1562691940.641 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-09T17:05:40.641Z,1562691940.641 [Default:A.Wait] Running Loop=1
2019-07-09T17:05:40.641Z,1562691940.641 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-09T17:05:48.674Z,1562691948.674 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-07-09T17:05:48.674Z,1562691948.674 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:05:48.724Z,1562691948.724 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:05:49.070Z,1562691949.070 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:05:49.070Z,1562691949.070 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-07-09T17:05:53.906Z,1562691953.906 [Default:A.Wait](INFO): Done Waiting.
2019-07-09T17:05:53.906Z,1562691953.906 [Default:A.Wait] Stopped
2019-07-09T17:05:53.906Z,1562691953.906 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-09T17:05:54.335Z,1562691954.335 [Default:CheckIn] Running Loop=1
2019-07-09T17:05:54.335Z,1562691954.335 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-09T17:05:54.335Z,1562691954.335 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-09T17:05:54.710Z,1562691954.710 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-07-09T17:08:30.035Z,1562692110.035 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-09T17:08:30.853Z,1562692110.853 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:34.493Z,1562692114.493 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:36.513Z,1562692116.513 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:38.529Z,1562692118.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:41.761Z,1562692121.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:44.589Z,1562692124.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:47.821Z,1562692127.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:49.852Z,1562692129.852 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-07-09T17:08:49.852Z,1562692129.852 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:08:49.879Z,1562692129.879 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:08:50.266Z,1562692130.266 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:08:50.266Z,1562692130.266 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-07-09T17:08:50.649Z,1562692130.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:53.881Z,1562692133.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:56.713Z,1562692136.713 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:08:59.945Z,1562692139.945 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:02.785Z,1562692142.785 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:06.005Z,1562692146.005 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:08.837Z,1562692148.837 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:11.657Z,1562692151.657 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:11.691Z,1562692151.691 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-07-09T17:09:11.694Z,1562692151.694 [BPC1](INFO): Received data from all battery sticks.
2019-07-09T17:09:14.485Z,1562692154.485 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:16.505Z,1562692156.505 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:18.529Z,1562692158.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:21.761Z,1562692161.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:24.585Z,1562692164.585 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:27.821Z,1562692167.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:30.645Z,1562692170.645 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:33.881Z,1562692173.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:36.705Z,1562692176.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:39.545Z,1562692179.545 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:41.957Z,1562692181.957 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:44.789Z,1562692184.789 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:48.017Z,1562692188.017 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:50.845Z,1562692190.845 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:53.673Z,1562692193.673 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:56.501Z,1562692196.501 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:09:58.521Z,1562692198.521 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:01.753Z,1562692201.753 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:04.581Z,1562692204.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:04.598Z,1562692204.598 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-09T17:10:04.598Z,1562692204.598 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19070910191074,35.0, -0.1,   0.0,10
2019-07-09T17:10:07.817Z,1562692207.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:10.641Z,1562692210.641 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:13.873Z,1562692213.873 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:16.701Z,1562692216.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:19.533Z,1562692219.533 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:22.769Z,1562692222.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:25.593Z,1562692225.593 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:28.825Z,1562692228.825 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:31.649Z,1562692231.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:34.885Z,1562692234.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:37.713Z,1562692237.713 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:40.549Z,1562692240.549 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:43.769Z,1562692243.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:46.604Z,1562692246.604 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:49.845Z,1562692249.845 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:52.661Z,1562692252.661 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:54.690Z,1562692254.690 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-09T17:05:54.3Z
2019-07-09T17:10:54.690Z,1562692254.690 [Default:CheckIn:Read_GPS] Stopped
2019-07-09T17:10:54.690Z,1562692254.690 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-09T17:10:55.098Z,1562692255.098 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-09T17:10:55.485Z,1562692255.485 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:57.524Z,1562692257.524 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:10:59.933Z,1562692259.933 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:00.976Z,1562692260.976 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20190709T170238/Courier0004.lzma
2019-07-09T17:11:01.584Z,1562692261.584 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-07-09T17:11:01.584Z,1562692261.584 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,32768,-32768,V
2019-07-09T17:11:01.782Z,1562692261.782 [DataOverHttps](INFO): Moved sent file to Logs/20190709T170238/Courier0004.lzma.bak
2019-07-09T17:11:01.782Z,1562692261.782 [DataOverHttps](INFO): SBD MOMSN=11435896
2019-07-09T17:11:02.769Z,1562692262.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:05.989Z,1562692265.989 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:08.817Z,1562692268.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:11.649Z,1562692271.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:14.473Z,1562692274.473 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:14.565Z,1562692274.565 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20190709T170238/Express0005.lzma
2019-07-09T17:11:15.370Z,1562692275.370 [DataOverHttps](INFO): Moved sent file to Logs/20190709T170238/Express0005.lzma.bak
2019-07-09T17:11:15.370Z,1562692275.370 [DataOverHttps](INFO): SBD MOMSN=11435898
2019-07-09T17:11:16.493Z,1562692276.493 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:17.722Z,1562692277.722 [Default:CheckIn:Read_Iridium] Stopped
2019-07-09T17:11:17.722Z,1562692277.722 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-09T17:11:17.722Z,1562692277.722 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-09T17:11:18.517Z,1562692278.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:21.749Z,1562692281.749 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:24.573Z,1562692284.573 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:27.813Z,1562692287.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:30.633Z,1562692290.633 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:33.869Z,1562692293.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:36.697Z,1562692296.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:39.521Z,1562692299.521 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:41.945Z,1562692301.945 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:44.777Z,1562692304.777 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:48.009Z,1562692308.009 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:50.841Z,1562692310.841 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:50.870Z,1562692310.870 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-07-09T17:11:50.870Z,1562692310.870 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:11:50.880Z,1562692310.880 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:11:51.278Z,1562692311.278 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:11:51.278Z,1562692311.278 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-07-09T17:11:53.665Z,1562692313.665 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:56.489Z,1562692316.489 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:11:58.513Z,1562692318.513 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:00.955Z,1562692320.955 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-09T17:12:00.956Z,1562692320.956 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19070910210674,35.0, -0.1,   :0,   0.00,   0.00,   0,-32768,-32768,-32768,-32768,V
2019-07-09T17:12:01.741Z,1562692321.741 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:04.573Z,1562692324.573 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:07.805Z,1562692327.805 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:10.629Z,1562692330.629 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:13.865Z,1562692333.865 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:16.693Z,1562692336.693 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:19.517Z,1562692339.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:22.749Z,1562692342.749 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:25.577Z,1562692345.577 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:28.817Z,1562692348.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:30.538Z,1562692350.538 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:12:30.539Z,1562692350.539 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.205395
2019-07-09T17:12:31.641Z,1562692351.641 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:34.873Z,1562692354.873 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:37.701Z,1562692357.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:40.533Z,1562692360.533 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:43.757Z,1562692363.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:46.593Z,1562692366.593 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:49.817Z,1562692369.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:52.653Z,1562692372.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:55.885Z,1562692375.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:12:58.713Z,1562692378.713 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:01.545Z,1562692381.545 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:04.769Z,1562692384.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:05.697Z,1562692385.697 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:13:07.597Z,1562692387.597 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:10.825Z,1562692390.825 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:13.665Z,1562692393.665 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:16.485Z,1562692396.485 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:18.505Z,1562692398.505 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:20.521Z,1562692400.521 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:20.942Z,1562692400.942 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-09T17:13:20.942Z,1562692400.942 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19070910222674,35.0, -0.1,   0.0, 0
2019-07-09T17:13:23.761Z,1562692403.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:26.581Z,1562692406.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:13:29.799Z,1562692409.799 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-09T17:13:29.799Z,1562692409.799 [NAL9602] Data Fault, FailCount= 1
2019-07-09T17:13:29.799Z,1562692409.799 [NAL9602](ERROR): Data Fault
2019-07-09T17:13:29.850Z,1562692409.850 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-09T17:13:30.203Z,1562692410.203 [NAL9602](INFO): Powering down
2019-07-09T17:13:31.046Z,1562692411.046 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-09T17:13:31.046Z,1562692411.046 [NAL9602] No Fault, FailCount= 1
2019-07-09T17:13:40.853Z,1562692420.853 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:14:00.503Z,1562692440.503 [NAL9602](INFO): Powering up NAL9602
2019-07-09T17:14:11.415Z,1562692451.415 [NAL9602](INFO): NAL9602 initialized
2019-07-09T17:14:12.257Z,1562692452.257 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:14.661Z,1562692454.661 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:16.001Z,1562692456.001 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:14:17.897Z,1562692457.897 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:20.721Z,1562692460.721 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:23.957Z,1562692463.957 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:26.785Z,1562692466.785 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:30.017Z,1562692470.017 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:32.845Z,1562692472.845 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:35.673Z,1562692475.673 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:38.501Z,1562692478.501 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:40.517Z,1562692480.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:43.749Z,1562692483.749 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:46.581Z,1562692486.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:49.809Z,1562692489.809 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:51.153Z,1562692491.153 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:14:51.850Z,1562692491.850 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-07-09T17:14:51.850Z,1562692491.850 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:14:51.860Z,1562692491.860 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:14:52.278Z,1562692492.278 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:14:52.278Z,1562692492.278 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-07-09T17:14:52.637Z,1562692492.637 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:55.869Z,1562692495.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:14:58.705Z,1562692498.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:01.538Z,1562692501.538 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:04.761Z,1562692504.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:07.585Z,1562692507.585 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:10.817Z,1562692510.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:13.645Z,1562692513.645 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:16.481Z,1562692516.481 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:18.497Z,1562692518.497 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:20.513Z,1562692520.513 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:23.745Z,1562692523.745 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:26.301Z,1562692526.301 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:15:26.577Z,1562692526.577 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:29.809Z,1562692529.809 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:32.637Z,1562692532.637 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:35.869Z,1562692535.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:38.697Z,1562692538.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:41.933Z,1562692541.933 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:44.757Z,1562692544.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:47.985Z,1562692547.985 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:50.813Z,1562692550.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:53.645Z,1562692553.645 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:56.873Z,1562692556.873 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:15:59.705Z,1562692559.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:01.449Z,1562692561.449 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:16:02.529Z,1562692562.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:05.764Z,1562692565.764 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:08.597Z,1562692568.597 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:11.833Z,1562692571.833 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:14.649Z,1562692574.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:17.885Z,1562692577.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:18.328Z,1562692578.328 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-09T17:16:18.328Z,1562692578.328 [Default:CheckIn:C.Wait] Stopped
2019-07-09T17:16:18.328Z,1562692578.328 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-09T17:16:18.328Z,1562692578.328 [Default:CheckIn:D] Running Loop=1
2019-07-09T17:16:18.722Z,1562692578.722 [Default:CheckIn:D] Stopped
2019-07-09T17:16:18.722Z,1562692578.722 [Default:CheckIn:E] Running Loop=1
2019-07-09T17:16:19.106Z,1562692579.106 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.634782 min 
2019-07-09T17:16:19.106Z,1562692579.106 [Default:CheckIn:E] Stopped
2019-07-09T17:16:19.106Z,1562692579.106 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-09T17:16:19.106Z,1562692579.106 [Default:CheckIn] Stopped
2019-07-09T17:16:19.107Z,1562692579.107 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-09T17:16:19.107Z,1562692579.107 [Default:CheckIn](INFO): Running loop #2
2019-07-09T17:16:19.107Z,1562692579.107 [Default:CheckIn] Running Loop=2
2019-07-09T17:16:19.107Z,1562692579.107 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-09T17:16:19.107Z,1562692579.107 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-09T17:16:20.709Z,1562692580.709 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:23.941Z,1562692583.941 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:26.769Z,1562692586.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:30.005Z,1562692590.005 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:32.829Z,1562692592.829 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:35.661Z,1562692595.661 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:36.597Z,1562692596.597 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:16:38.489Z,1562692598.489 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:40.509Z,1562692600.509 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:42.525Z,1562692602.525 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:45.762Z,1562692605.762 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:48.585Z,1562692608.585 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:51.821Z,1562692611.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:54.645Z,1562692614.645 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:16:57.877Z,1562692617.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:00.713Z,1562692620.713 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:03.537Z,1562692623.537 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:05.957Z,1562692625.957 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:08.789Z,1562692628.789 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:11.745Z,1562692631.745 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:17:12.021Z,1562692632.021 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:14.845Z,1562692634.845 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:17.677Z,1562692637.677 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:20.505Z,1562692640.505 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:22.541Z,1562692642.541 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:25.757Z,1562692645.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:28.581Z,1562692648.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:31.813Z,1562692651.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:34.645Z,1562692654.645 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:37.877Z,1562692657.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:40.701Z,1562692660.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:43.533Z,1562692663.533 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:46.765Z,1562692666.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:46.893Z,1562692666.893 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:17:49.589Z,1562692669.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:52.825Z,1562692672.825 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:52.849Z,1562692672.849 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-07-09T17:17:52.849Z,1562692672.849 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:17:52.859Z,1562692672.859 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:17:53.273Z,1562692673.273 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:17:53.273Z,1562692673.273 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-07-09T17:17:55.653Z,1562692675.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:17:58.493Z,1562692678.493 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:00.497Z,1562692680.497 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:02.517Z,1562692682.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:05.749Z,1562692685.749 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:08.577Z,1562692688.577 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:11.809Z,1562692691.809 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:14.637Z,1562692694.637 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:17.873Z,1562692697.873 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:20.701Z,1562692700.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:22.041Z,1562692702.041 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:18:23.929Z,1562692703.929 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:26.761Z,1562692706.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:29.997Z,1562692709.997 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:32.817Z,1562692712.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:35.653Z,1562692715.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:38.877Z,1562692718.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:41.709Z,1562692721.709 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:44.537Z,1562692724.537 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:47.765Z,1562692727.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:50.593Z,1562692730.593 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:53.833Z,1562692733.833 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:56.657Z,1562692736.657 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:18:57.191Z,1562692737.191 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:18:59.885Z,1562692739.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:02.713Z,1562692742.713 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:05.945Z,1562692745.945 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:08.777Z,1562692748.777 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:12.005Z,1562692752.005 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:14.837Z,1562692754.837 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:17.665Z,1562692757.665 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:20.489Z,1562692760.489 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:22.513Z,1562692762.513 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:25.745Z,1562692765.745 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:28.569Z,1562692768.569 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:31.801Z,1562692771.801 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:32.337Z,1562692772.337 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-07-09T17:19:34.629Z,1562692774.629 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:37.865Z,1562692777.865 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:40.697Z,1562692780.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:43.517Z,1562692783.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:46.753Z,1562692786.753 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:49.577Z,1562692789.577 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:52.813Z,1562692792.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:55.637Z,1562692795.637 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:19:58.877Z,1562692798.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:01.697Z,1562692801.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:04.533Z,1562692804.533 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:07.757Z,1562692807.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:10.593Z,1562692810.593 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:13.821Z,1562692813.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:16.649Z,1562692816.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:19.477Z,1562692819.477 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:21.509Z,1562692821.509 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:23.917Z,1562692823.917 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:26.745Z,1562692826.745 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:29.977Z,1562692829.977 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:32.809Z,1562692832.809 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:36.037Z,1562692836.037 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:38.869Z,1562692838.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:41.693Z,1562692841.693 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:44.521Z,1562692844.521 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:47.757Z,1562692847.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:50.589Z,1562692850.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:53.813Z,1562692853.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:53.846Z,1562692853.846 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2019-07-09T17:20:53.846Z,1562692853.846 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:20:53.857Z,1562692853.857 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:20:54.282Z,1562692854.282 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:20:54.282Z,1562692854.282 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2019-07-09T17:20:56.657Z,1562692856.657 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:20:59.881Z,1562692859.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:02.705Z,1562692862.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:05.933Z,1562692865.933 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:08.765Z,1562692868.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:11.997Z,1562692871.997 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:14.821Z,1562692874.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:17.649Z,1562692877.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:19.282Z,1562692879.282 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-09T17:16:19.1Z
2019-07-09T17:21:19.282Z,1562692879.282 [Default:CheckIn:Read_GPS] Stopped
2019-07-09T17:21:19.282Z,1562692879.282 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-09T17:21:20.477Z,1562692880.477 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:22.497Z,1562692882.497 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:24.517Z,1562692884.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:27.749Z,1562692887.749 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:30.581Z,1562692890.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:33.821Z,1562692893.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:36.641Z,1562692896.641 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:39.869Z,1562692899.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:42.701Z,1562692902.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:45.525Z,1562692905.525 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:47.949Z,1562692907.949 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:49.061Z,1562692909.061 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003327
2019-07-09T17:21:50.781Z,1562692910.781 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:54.012Z,1562692914.012 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:55.960Z,1562692915.960 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20190709T170238/Express0008.lzma
2019-07-09T17:21:56.766Z,1562692916.766 [DataOverHttps](INFO): Moved sent file to Logs/20190709T170238/Express0008.lzma.bak
2019-07-09T17:21:56.767Z,1562692916.767 [DataOverHttps](INFO): SBD MOMSN=11436004
2019-07-09T17:21:56.837Z,1562692916.837 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:21:59.270Z,1562692919.270 [Default:CheckIn:Read_Iridium] Stopped
2019-07-09T17:21:59.270Z,1562692919.270 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-09T17:21:59.270Z,1562692919.270 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-09T17:21:59.669Z,1562692919.669 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:02.493Z,1562692922.493 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:04.513Z,1562692924.513 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:07.761Z,1562692927.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:10.581Z,1562692930.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:13.805Z,1562692933.805 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:16.649Z,1562692936.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:19.869Z,1562692939.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:22.701Z,1562692942.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:25.525Z,1562692945.525 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:28.753Z,1562692948.753 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:31.589Z,1562692951.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:34.816Z,1562692954.816 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:37.641Z,1562692957.641 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:40.877Z,1562692960.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:43.721Z,1562692963.721 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:46.529Z,1562692966.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:49.761Z,1562692969.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:52.593Z,1562692972.593 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:55.825Z,1562692975.825 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:22:58.653Z,1562692978.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:01.481Z,1562692981.481 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:03.497Z,1562692983.497 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:05.925Z,1562692985.925 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:08.752Z,1562692988.752 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:11.981Z,1562692991.981 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:14.813Z,1562692994.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:18.045Z,1562692998.045 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:20.881Z,1562693000.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:23.697Z,1562693003.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:26.529Z,1562693006.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:29.757Z,1562693009.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:32.592Z,1562693012.592 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:35.823Z,1562693015.823 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:38.649Z,1562693018.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:41.881Z,1562693021.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:44.713Z,1562693024.713 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:47.937Z,1562693027.937 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:50.769Z,1562693030.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:51.249Z,1562693031.249 [CommandLine](IMPORTANT): got command run ./Missions/DUSBL_Tracking.xml
2019-07-09T17:23:51.250Z,1562693031.250 [MissionManager](INFO): Loading Mission: ./Missions/DUSBL_Tracking.xml
2019-07-09T17:23:51.278Z,1562693031.278 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 10.000000 min
2019-07-09T17:23:51.282Z,1562693031.282 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-07-09T17:23:51.285Z,1562693031.285 [MissionManager](INFO): DefineArg DUSBL.TrackingUpdatePeriod = 2.000000 s
2019-07-09T17:23:51.290Z,1562693031.290 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-07-09T17:23:51.294Z,1562693031.294 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = DUSBL_Hydroid.loadAtStartup
2019-07-09T17:23:51.295Z,1562693031.295 [DUSBL:A.Pitch](DEBUG): Construct.
2019-07-09T17:23:51.302Z,1562693031.302 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-07-09T17:23:51.575Z,1562693031.575 [DUSBL:RequestRepeater:A.Wait](DEBUG): Construct Wait.
2019-07-09T17:23:51.579Z,1562693031.579 [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>10</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>2</Value></DefineArg>
    
    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Sensor:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

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

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

    
        <Estimation:TrackAcousticContact>
            <Parallel/>
            <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
            <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
            <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
        </Estimation:TrackAcousticContact>
        
      <Aggregate Id="RequestRepeater">

        <Sequence/>
        
          <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="MissionTimeout"/></Setting>            
          </Guidance:Wait>
      </Aggregate>

</Mission>


2019-07-09T17:23:51.613Z,1562693031.613 [CommandLine](IMPORTANT): Running ./Missions/DUSBL_Tracking.xml
2019-07-09T17:23:51.639Z,1562693031.639 [Default] Stopped
2019-07-09T17:23:51.639Z,1562693031.639 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-09T17:23:51.639Z,1562693031.639 [Default:B.GoToSurface] Stopped
2019-07-09T17:23:51.639Z,1562693031.639 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-09T17:23:51.639Z,1562693031.639 [Default:CheckIn] Stopped
2019-07-09T17:23:51.639Z,1562693031.639 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-09T17:23:51.639Z,1562693031.639 [Default:CheckIn:C.Wait] Stopped
2019-07-09T17:23:51.639Z,1562693031.639 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-09T17:23:51.640Z,1562693031.640 [MissionManager](IMPORTANT): Started mission DUSBL
2019-07-09T17:23:51.640Z,1562693031.640 [DUSBL] Running Loop=1
2019-07-09T17:23:51.640Z,1562693031.640 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-07-09T17:23:51.640Z,1562693031.640 [DUSBL:A.Pitch] Running Loop=1
2019-07-09T17:23:51.640Z,1562693031.640 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-07-09T17:23:51.645Z,1562693031.645 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-09T17:23:51.645Z,1562693031.645 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-07-09T17:23:51.645Z,1562693031.645 [DUSBL:C.] Running Loop=1
2019-07-09T17:23:51.645Z,1562693031.645 [DUSBL:C.](INFO): Initializing TrackAcousticContact.
2019-07-09T17:23:51.645Z,1562693031.645 [DUSBL:RequestRepeater] Running Loop=1
2019-07-09T17:23:51.645Z,1562693031.645 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-07-09T17:23:51.646Z,1562693031.646 [DUSBL:RequestRepeater:A.Wait] Running Loop=1
2019-07-09T17:23:51.646Z,1562693031.646 [DUSBL:RequestRepeater:A.Wait](DEBUG): Initialize Wait Component.
2019-07-09T17:23:51.646Z,1562693031.646 [DUSBL:C.] Running Loop=1
2019-07-09T17:23:51.647Z,1562693031.647 [DUSBL:B.SetSpeed] Running Loop=1
2019-07-09T17:23:51.647Z,1562693031.647 [DUSBL:A.Pitch] Running Loop=1
2019-07-09T17:23:54.001Z,1562693034.001 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:54.034Z,1562693034.034 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:23:54.829Z,1562693034.829 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2019-07-09T17:23:54.829Z,1562693034.829 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:23:54.847Z,1562693034.847 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:23:55.279Z,1562693035.279 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:23:55.279Z,1562693035.279 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2019-07-09T17:23:56.451Z,1562693036.451 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:23:56.829Z,1562693036.829 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:23:58.466Z,1562693038.466 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:23:59.653Z,1562693039.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:24:00.494Z,1562693040.494 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:02.485Z,1562693042.485 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:24:02.534Z,1562693042.534 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:04.509Z,1562693044.509 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:24:04.539Z,1562693044.539 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:06.521Z,1562693046.521 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:24:06.552Z,1562693046.552 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:07.324Z,1562693047.324 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:24:07.730Z,1562693047.730 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:24:08.579Z,1562693048.579 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:09.761Z,1562693049.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:24:10.566Z,1562693050.566 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-09T17:24:10.622Z,1562693050.622 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:12.567Z,1562693052.567 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-09T17:24:12.567Z,1562693052.567 [NAL9602] Data Fault, FailCount= 2
2019-07-09T17:24:12.567Z,1562693052.567 [NAL9602](ERROR): Data Fault
2019-07-09T17:24:12.602Z,1562693052.602 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-09T17:24:12.975Z,1562693052.975 [NAL9602](INFO): Powering down
2019-07-09T17:24:13.002Z,1562693053.002 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:13.816Z,1562693053.816 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-09T17:24:13.816Z,1562693053.816 [NAL9602] No Fault, FailCount= 2
2019-07-09T17:24:15.024Z,1562693055.024 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:17.050Z,1562693057.050 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:17.830Z,1562693057.830 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:24:18.232Z,1562693058.232 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:24:19.054Z,1562693059.054 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:21.102Z,1562693061.102 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:23.520Z,1562693063.520 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:25.551Z,1562693065.551 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:27.946Z,1562693067.946 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:29.974Z,1562693069.974 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:30.763Z,1562693070.763 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:24:31.152Z,1562693071.152 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:24:31.997Z,1562693071.997 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:33.986Z,1562693073.986 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-09T17:24:34.010Z,1562693074.010 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:34.797Z,1562693074.797 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:24:35.215Z,1562693075.215 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:24:36.024Z,1562693076.024 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:38.079Z,1562693078.079 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:40.478Z,1562693080.478 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:42.499Z,1562693082.499 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:43.275Z,1562693083.275 [NAL9602](INFO): Powering up NAL9602
2019-07-09T17:24:44.524Z,1562693084.524 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:46.534Z,1562693086.534 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:47.312Z,1562693087.312 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:24:47.730Z,1562693087.730 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:24:48.554Z,1562693088.554 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:50.560Z,1562693090.560 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-09T17:24:50.592Z,1562693090.592 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:51.351Z,1562693091.351 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:24:51.776Z,1562693091.776 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:24:52.594Z,1562693092.594 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:54.209Z,1562693094.209 [NAL9602](INFO): NAL9602 initialized
2019-07-09T17:24:54.629Z,1562693094.629 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:55.005Z,1562693095.005 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:24:57.046Z,1562693097.046 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:57.836Z,1562693097.836 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:24:59.054Z,1562693099.054 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:24:59.853Z,1562693099.853 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:01.082Z,1562693101.082 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:01.877Z,1562693101.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:03.094Z,1562693103.094 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:05.101Z,1562693105.101 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:05.138Z,1562693105.138 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:07.547Z,1562693107.547 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:07.945Z,1562693107.945 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:09.573Z,1562693109.573 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:10.340Z,1562693110.340 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:25:10.744Z,1562693110.744 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:25:11.165Z,1562693111.165 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:11.616Z,1562693111.616 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:13.578Z,1562693113.578 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-09T17:25:13.989Z,1562693113.989 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:14.018Z,1562693114.018 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:14.791Z,1562693114.791 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:25:15.211Z,1562693115.211 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:25:16.022Z,1562693116.022 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:17.241Z,1562693117.241 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:18.074Z,1562693118.074 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:20.053Z,1562693120.053 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:20.078Z,1562693120.078 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:20.851Z,1562693120.851 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:25:21.256Z,1562693121.256 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:25:22.094Z,1562693122.094 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:22.877Z,1562693122.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:24.078Z,1562693124.078 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-09T17:25:24.106Z,1562693124.106 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:24.884Z,1562693124.884 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:25:25.288Z,1562693125.288 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:25:26.109Z,1562693126.109 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:26.134Z,1562693126.134 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:28.160Z,1562693128.160 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:28.937Z,1562693128.937 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:30.166Z,1562693130.166 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:31.765Z,1562693131.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:32.258Z,1562693132.258 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:34.601Z,1562693134.601 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:34.622Z,1562693134.622 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:36.638Z,1562693136.638 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:37.407Z,1562693137.407 [Micromodem](INFO): Nmea out: $CCPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*53

2019-07-09T17:25:37.820Z,1562693137.820 [Micromodem](INFO): Nmea in: $SNPGT,14500,28,4A1C0370,1000,24000,0,0,0,0,2000,0*4E

2019-07-09T17:25:37.845Z,1562693137.845 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:38.729Z,1562693138.729 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2019-07-09T17:25:38.729Z,1562693138.729 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-07-09T17:25:38.729Z,1562693138.729 [RDI_Pathfinder](ERROR): Communications Fault
2019-07-09T17:25:38.729Z,1562693138.729 [RDI_Pathfinder](ERROR): Failed to parse:
2019-07-09T17:25:38.738Z,1562693138.738 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:38.783Z,1562693138.783 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-07-09T17:25:39.105Z,1562693139.105 [RDI_Pathfinder](INFO): Powering down
2019-07-09T17:25:39.872Z,1562693139.872 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-07-09T17:25:39.872Z,1562693139.872 [RDI_Pathfinder] No Fault, FailCount= 1
2019-07-09T17:25:40.642Z,1562693140.642 [DUSBL_Hydroid](ERROR): No response from remote modem.
2019-07-09T17:25:40.657Z,1562693140.657 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:41.106Z,1562693141.106 [DUSBL:C.](INFO): *** querying acoustic contact ***
2019-07-09T17:25:41.472Z,1562693141.472 [CommandLine](IMPORTANT): got command stop
2019-07-09T17:25:41.489Z,1562693141.489 [CommandLine](IMPORTANT): Scheduling is paused
2019-07-09T17:25:41.490Z,1562693141.490 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-07-09T17:25:41.510Z,1562693141.510 [MissionManager](INFO): MissionManager is completed.
2019-07-09T17:25:41.511Z,1562693141.511 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL] Stopped
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:A.Pitch] Stopped
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:B.SetSpeed] Stopped
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:C.] Stopped
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:RequestRepeater] Stopped
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:RequestRepeater:A.Wait] Stopped
2019-07-09T17:25:41.511Z,1562693141.511 [DUSBL:RequestRepeater:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-09T17:25:41.906Z,1562693141.906 [MissionManager](IMPORTANT): Started mission Default
2019-07-09T17:25:41.906Z,1562693141.906 [Default] Running Loop=1
2019-07-09T17:25:41.906Z,1562693141.906 [Default](DEBUG): Aggregate::initialize Default
2019-07-09T17:25:41.906Z,1562693141.906 [Default:B.GoToSurface] Running Loop=1
2019-07-09T17:25:41.906Z,1562693141.906 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-09T17:25:41.906Z,1562693141.906 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-09T17:25:41.907Z,1562693141.907 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-09T17:25:41.907Z,1562693141.907 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-09T17:25:41.907Z,1562693141.907 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-09T17:25:41.908Z,1562693141.908 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-09T17:25:41.908Z,1562693141.908 [Default:A.Wait] Running Loop=1
2019-07-09T17:25:41.908Z,1562693141.908 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-09T17:25:43.897Z,1562693143.897 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:46.713Z,1562693146.713 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:49.545Z,1562693149.545 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:51.565Z,1562693151.565 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:53.188Z,1562693153.188 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-07-09T17:25:53.985Z,1562693153.985 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:55.239Z,1562693155.239 [Default:A.Wait](INFO): Done Waiting.
2019-07-09T17:25:55.239Z,1562693155.239 [Default:A.Wait] Stopped
2019-07-09T17:25:55.239Z,1562693155.239 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-09T17:25:55.614Z,1562693155.614 [Default:CheckIn] Running Loop=1
2019-07-09T17:25:55.614Z,1562693155.614 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-09T17:25:55.614Z,1562693155.614 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-09T17:25:56.817Z,1562693156.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:25:59.641Z,1562693159.641 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:02.873Z,1562693162.873 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:05.705Z,1562693165.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:08.533Z,1562693168.533 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:11.773Z,1562693171.773 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:14.593Z,1562693174.593 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:17.825Z,1562693177.825 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:20.653Z,1562693180.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:23.885Z,1562693183.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:26.709Z,1562693186.709 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:28.337Z,1562693188.337 [RDI_Pathfinder](ERROR): Failed to parse:
:SA,   +0.00,   +0.00,  0.00
2019-07-09T17:26:29.945Z,1562693189.945 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:32.773Z,1562693192.773 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:36.004Z,1562693196.004 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:38.837Z,1562693198.837 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:41.657Z,1562693201.657 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:44.485Z,1562693204.485 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:46.140Z,1562693206.140 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-07-09T17:26:46.145Z,1562693206.145 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-

2019-07-09T17:26:46.509Z,1562693206.509 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:48.529Z,1562693208.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:51.769Z,1562693211.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:54.589Z,1562693214.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:26:55.809Z,1562693215.809 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2019-07-09T17:26:55.809Z,1562693215.809 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:26:55.819Z,1562693215.819 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:26:56.238Z,1562693216.238 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:26:56.238Z,1562693216.238 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2019-07-09T17:26:57.817Z,1562693217.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:00.649Z,1562693220.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:01.565Z,1562693221.565 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2019-07-09T17:27:01.565Z,1562693221.565 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-07-09T17:27:01.565Z,1562693221.565 [RDI_Pathfinder](ERROR): Communications Fault
2019-07-09T17:27:01.565Z,1562693221.565 [RDI_Pathfinder](ERROR): Failed to parse:
2019-07-09T17:27:01.583Z,1562693221.583 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-07-09T17:27:01.937Z,1562693221.937 [RDI_Pathfinder](INFO): Powering down
2019-07-09T17:27:02.686Z,1562693222.686 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-07-09T17:27:02.686Z,1562693222.686 [RDI_Pathfinder] No Fault, FailCount= 1
2019-07-09T17:27:03.881Z,1562693223.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:06.705Z,1562693226.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:09.537Z,1562693229.537 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:11.957Z,1562693231.957 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:14.789Z,1562693234.789 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:16.012Z,1562693236.012 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-07-09T17:27:18.017Z,1562693238.017 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:20.869Z,1562693240.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:23.677Z,1562693243.677 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:26.521Z,1562693246.521 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:29.757Z,1562693249.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:31.363Z,1562693251.363 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-09T17:27:31.363Z,1562693251.363 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19070910363751,35.0, -0.1,   0.0, 0
2019-07-09T17:27:32.561Z,1562693252.561 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:35.793Z,1562693255.793 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:38.621Z,1562693258.621 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:41.853Z,1562693261.853 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:44.681Z,1562693264.681 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:47.925Z,1562693267.925 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:50.741Z,1562693270.741 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:53.973Z,1562693273.973 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:27:56.801Z,1562693276.801 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:00.045Z,1562693280.045 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:02.865Z,1562693282.865 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:05.697Z,1562693285.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:08.521Z,1562693288.521 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:11.757Z,1562693291.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:14.577Z,1562693294.577 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:17.813Z,1562693297.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:20.641Z,1562693300.641 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:23.869Z,1562693303.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:26.697Z,1562693306.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:29.937Z,1562693309.937 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:32.765Z,1562693312.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:36.009Z,1562693316.009 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:38.821Z,1562693318.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:41.649Z,1562693321.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:44.881Z,1562693324.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:47.705Z,1562693327.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:50.533Z,1562693330.533 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:53.765Z,1562693333.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:56.597Z,1562693336.597 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:28:59.825Z,1562693339.825 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:02.657Z,1562693342.657 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:05.885Z,1562693345.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:08.717Z,1562693348.717 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:11.945Z,1562693351.945 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:14.773Z,1562693354.773 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:18.013Z,1562693358.013 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:20.840Z,1562693360.840 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:23.669Z,1562693363.669 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:26.493Z,1562693366.493 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:28.509Z,1562693368.509 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:30.537Z,1562693370.537 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:33.769Z,1562693373.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:36.593Z,1562693376.593 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:39.821Z,1562693379.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:42.653Z,1562693382.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:45.881Z,1562693385.881 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:48.709Z,1562693388.709 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:51.541Z,1562693391.541 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:53.973Z,1562693393.973 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:56.789Z,1562693396.789 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:29:56.813Z,1562693396.813 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2019-07-09T17:29:56.813Z,1562693396.813 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:29:56.823Z,1562693396.823 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:29:57.235Z,1562693397.235 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:29:57.235Z,1562693397.235 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2019-07-09T17:30:00.021Z,1562693400.021 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:02.849Z,1562693402.849 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:05.677Z,1562693405.677 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:08.509Z,1562693408.509 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:10.529Z,1562693410.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:13.757Z,1562693413.757 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:16.589Z,1562693416.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:19.817Z,1562693419.817 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:22.649Z,1562693422.649 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:25.877Z,1562693425.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:28.705Z,1562693428.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:31.537Z,1562693431.537 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:34.769Z,1562693434.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:37.601Z,1562693437.601 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:40.828Z,1562693440.828 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:43.657Z,1562693443.657 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:46.485Z,1562693446.485 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:48.505Z,1562693448.505 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:50.529Z,1562693450.529 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:53.761Z,1562693453.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:55.794Z,1562693455.794 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-09T17:25:55.6Z
2019-07-09T17:30:55.794Z,1562693455.794 [Default:CheckIn:Read_GPS] Stopped
2019-07-09T17:30:55.795Z,1562693455.795 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-09T17:30:56.665Z,1562693456.665 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:59.885Z,1562693459.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:30:59.921Z,1562693459.921 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20190709T170238/Express0011.lzma
2019-07-09T17:31:00.730Z,1562693460.730 [DataOverHttps](INFO): Moved sent file to Logs/20190709T170238/Express0011.lzma.bak
2019-07-09T17:31:00.730Z,1562693460.730 [DataOverHttps](INFO): SBD MOMSN=11436064
2019-07-09T17:31:02.709Z,1562693462.709 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:03.179Z,1562693463.179 [Default:CheckIn:Read_Iridium] Stopped
2019-07-09T17:31:03.179Z,1562693463.179 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-09T17:31:03.179Z,1562693463.179 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-09T17:31:05.937Z,1562693465.937 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:08.765Z,1562693468.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:11.993Z,1562693471.993 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:14.821Z,1562693474.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:17.653Z,1562693477.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:20.477Z,1562693480.477 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:22.501Z,1562693482.501 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:24.517Z,1562693484.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:27.749Z,1562693487.749 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:30.581Z,1562693490.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:33.809Z,1562693493.809 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:36.641Z,1562693496.641 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:39.869Z,1562693499.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:42.701Z,1562693502.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:45.525Z,1562693505.525 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:47.984Z,1562693507.984 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:50.781Z,1562693510.781 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:54.013Z,1562693514.013 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:56.841Z,1562693516.841 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:31:59.669Z,1562693519.669 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:02.497Z,1562693522.497 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:04.513Z,1562693524.513 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:06.978Z,1562693526.978 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-07-09T17:32:06.978Z,1562693526.978 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768V
2019-07-09T17:32:07.749Z,1562693527.749 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:10.581Z,1562693530.581 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:13.805Z,1562693533.805 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:16.637Z,1562693536.637 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:19.869Z,1562693539.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:22.697Z,1562693542.697 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:25.525Z,1562693545.525 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:28.753Z,1562693548.753 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:31.585Z,1562693551.585 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:34.821Z,1562693554.821 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:37.645Z,1562693557.645 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:40.873Z,1562693560.873 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:43.705Z,1562693563.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:46.533Z,1562693566.533 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:49.769Z,1562693569.769 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:52.589Z,1562693572.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:55.833Z,1562693575.833 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:32:57.849Z,1562693577.849 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2019-07-09T17:32:57.849Z,1562693577.849 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:32:57.863Z,1562693577.863 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:32:58.278Z,1562693578.278 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:32:58.278Z,1562693578.278 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2019-07-09T17:32:58.653Z,1562693578.653 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:01.481Z,1562693581.481 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:03.497Z,1562693583.497 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:05.921Z,1562693585.921 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:08.753Z,1562693588.753 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:11.981Z,1562693591.981 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:14.813Z,1562693594.813 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:18.041Z,1562693598.041 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:20.869Z,1562693600.869 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:23.701Z,1562693603.701 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:26.525Z,1562693606.525 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:29.761Z,1562693609.761 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:32.589Z,1562693612.589 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:35.825Z,1562693615.825 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:38.645Z,1562693618.645 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:41.877Z,1562693621.877 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:44.705Z,1562693624.705 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:47.953Z,1562693627.953 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:50.765Z,1562693630.765 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:53.997Z,1562693633.997 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:56.841Z,1562693636.841 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:33:59.656Z,1562693639.656 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:02.885Z,1562693642.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:05.717Z,1562693645.717 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:08.545Z,1562693648.545 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:11.773Z,1562693651.773 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:14.609Z,1562693654.609 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:17.837Z,1562693657.837 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:20.661Z,1562693660.661 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:23.909Z,1562693663.909 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:26.743Z,1562693666.743 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:29.986Z,1562693669.986 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:32.809Z,1562693672.809 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:36.029Z,1562693676.029 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:38.845Z,1562693678.845 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:41.673Z,1562693681.673 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:44.517Z,1562693684.517 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:47.729Z,1562693687.729 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:50.573Z,1562693690.573 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:53.797Z,1562693693.797 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:34:56.619Z,1562693696.619 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-09T17:34:56.619Z,1562693696.619 [NAL9602] Data Fault, FailCount= 3
2019-07-09T17:34:56.619Z,1562693696.619 [NAL9602](ERROR): Data Fault
2019-07-09T17:34:56.728Z,1562693696.728 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-09T17:34:57.012Z,1562693697.012 [NAL9602](INFO): Powering down
2019-07-09T17:34:57.997Z,1562693697.997 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-09T17:34:57.997Z,1562693697.997 [NAL9602] No Fault, FailCount= 3
2019-07-09T17:35:27.307Z,1562693727.307 [NAL9602](INFO): Powering up NAL9602
2019-07-09T17:35:29.027Z,1562693729.027 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2019-07-09T17:35:29.027Z,1562693729.027 [RDI_Pathfinder](ERROR): Failed to parse:
:RA68,-32768,-32768,V
2019-07-09T17:35:38.215Z,1562693738.215 [NAL9602](INFO): NAL9602 initialized
2019-07-09T17:35:39.037Z,1562693739.037 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:41.885Z,1562693741.885 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:43.905Z,1562693743.905 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:45.913Z,1562693745.913 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:49.137Z,1562693749.137 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:51.973Z,1562693751.973 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:54.997Z,1562693754.997 [CommandLine](IMPORTANT): got command get DUSBL_Hydroid.detectionThreshold
2019-07-09T17:35:54.998Z,1562693754.998 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold 32 count
2019-07-09T17:35:55.197Z,1562693755.197 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:58.032Z,1562693758.032 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:35:58.853Z,1562693758.853 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2019-07-09T17:35:58.853Z,1562693758.853 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-09T17:35:58.863Z,1562693758.863 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-09T17:35:59.275Z,1562693759.275 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-09T17:35:59.275Z,1562693759.275 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2019-07-09T17:36:01.257Z,1562693761.257 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:36:03.694Z,1562693763.694 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-09T17:36:03.694Z,1562693763.694 [Default:CheckIn:C.Wait] Stopped
2019-07-09T17:36:03.694Z,1562693763.694 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-09T17:36:03.694Z,1562693763.694 [Default:CheckIn:D] Running Loop=1
2019-07-09T17:36:04.089Z,1562693764.089 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:36:04.114Z,1562693764.114 [Default:CheckIn:D] Stopped
2019-07-09T17:36:04.114Z,1562693764.114 [Default:CheckIn:E] Running Loop=1
2019-07-09T17:36:04.530Z,1562693764.530 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.370134 min 
2019-07-09T17:36:04.530Z,1562693764.530 [Default:CheckIn:E] Stopped
2019-07-09T17:36:04.530Z,1562693764.530 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-09T17:36:04.530Z,1562693764.530 [Default:CheckIn] Stopped
2019-07-09T17:36:04.530Z,1562693764.530 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-09T17:36:04.531Z,1562693764.531 [Default:CheckIn](INFO): Running loop #2
2019-07-09T17:36:04.531Z,1562693764.531 [Default:CheckIn] Running Loop=2
2019-07-09T17:36:04.531Z,1562693764.531 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-09T17:36:04.531Z,1562693764.531 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-09T17:36:06.917Z,1562693766.917 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:36:09.135Z,1562693769.135 [CommandLine](IMPORTANT): got command restart application
2019-07-09T17:36:10.141Z,1562693770.141 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:10.141Z,1562693770.141 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.145Z,1562693770.145 [NAL9602](DEBUG): Fix Requested
2019-07-09T17:36:10.257Z,1562693770.257 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-07-09T17:36:10.257Z,1562693770.257 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.257Z,1562693770.257 [CommandLine](INFO): Join timeout helper Thread ID is 5298
2019-07-09T17:36:10.258Z,1562693770.258 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-07-09T17:36:10.258Z,1562693770.258 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.259Z,1562693770.259 [NavChartDb](INFO): Join timeout helper Thread ID is 5299
2019-07-09T17:36:10.337Z,1562693770.337 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:10.337Z,1562693770.337 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.357Z,1562693770.357 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-07-09T17:36:10.357Z,1562693770.357 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.357Z,1562693770.357 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 5300
2019-07-09T17:36:10.625Z,1562693770.625 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:10.625Z,1562693770.625 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-07-09T17:36:10.626Z,1562693770.626 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.637Z,1562693770.637 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-07-09T17:36:10.637Z,1562693770.637 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.637Z,1562693770.637 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 5301
2019-07-09T17:36:10.833Z,1562693770.833 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:10.833Z,1562693770.833 [CTD_NeilBrown](INFO): Powering down
2019-07-09T17:36:10.845Z,1562693770.845 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.857Z,1562693770.857 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-07-09T17:36:10.857Z,1562693770.857 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:10.857Z,1562693770.857 [Radio_Surface](INFO): Join timeout helper Thread ID is 5302
2019-07-09T17:36:11.085Z,1562693771.085 [Radio_Surface](INFO): Powering down
2019-07-09T17:36:11.086Z,1562693771.086 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:11.086Z,1562693771.086 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.110Z,1562693771.110 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-07-09T17:36:11.110Z,1562693771.110 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.110Z,1562693771.110 [DataOverHttps](INFO): Join timeout helper Thread ID is 5303
2019-07-09T17:36:11.185Z,1562693771.185 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:11.185Z,1562693771.185 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.197Z,1562693771.197 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-07-09T17:36:11.198Z,1562693771.198 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.198Z,1562693771.198 [logger](INFO): Join timeout helper Thread ID is 5304
2019-07-09T17:36:11.205Z,1562693771.205 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:11.205Z,1562693771.205 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.217Z,1562693771.217 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-07-09T17:36:11.218Z,1562693771.218 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.218Z,1562693771.218 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-07-09T17:36:11.218Z,1562693771.218 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.218Z,1562693771.218 [controlThread](INFO): Join timeout helper Thread ID is 5305
2019-07-09T17:36:11.333Z,1562693771.333 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-09T17:36:11.333Z,1562693771.333 [controlThread](DEBUG): Uninitializing ControlThread
2019-07-09T17:36:11.334Z,1562693771.334 [AHRS_M2](INFO): Powering down
2019-07-09T17:36:11.405Z,1562693771.405 [DUSBL_Hydroid](INFO): Powering down
2019-07-09T17:36:11.477Z,1562693771.477 [Micromodem](INFO): Powering down
2019-07-09T17:36:11.573Z,1562693771.573 [NAL9602](INFO): Powering down
2019-07-09T17:36:11.645Z,1562693771.645 [RDI_Pathfinder](INFO): Powering down
2019-07-09T17:36:11.646Z,1562693771.646 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-07-09T17:36:11.647Z,1562693771.647 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-07-09T17:36:11.647Z,1562693771.647 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-07-09T17:36:11.648Z,1562693771.648 [MissionManager](INFO): Uninitializing Mission Default
2019-07-09T17:36:11.648Z,1562693771.648 [Default] Stopped
2019-07-09T17:36:11.648Z,1562693771.648 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-09T17:36:11.648Z,1562693771.648 [Default:B.GoToSurface] Stopped
2019-07-09T17:36:11.648Z,1562693771.648 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-09T17:36:11.648Z,1562693771.648 [Default:CheckIn] Stopped
2019-07-09T17:36:11.649Z,1562693771.649 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-09T17:36:11.649Z,1562693771.649 [Default:CheckIn:Read_GPS] Stopped
2019-07-09T17:36:11.651Z,1562693771.651 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-07-09T17:36:11.651Z,1562693771.651 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-07-09T17:36:11.652Z,1562693771.652 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-07-09T17:36:11.652Z,1562693771.652 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-07-09T17:36:11.652Z,1562693771.652 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-07-09T17:36:11.652Z,1562693771.652 [BuoyancyServo](INFO): Powering down
2019-07-09T17:36:11.665Z,1562693771.665 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-07-09T17:36:11.665Z,1562693771.665 [ElevatorServo](INFO): Powering down
2019-07-09T17:36:11.666Z,1562693771.666 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-07-09T17:36:11.666Z,1562693771.666 [MassServo](INFO): Powering down
2019-07-09T17:36:11.667Z,1562693771.667 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-09T17:36:11.667Z,1562693771.667 [RudderServo](INFO): Powering down
2019-07-09T17:36:11.667Z,1562693771.667 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-07-09T17:36:11.668Z,1562693771.668 [ThrusterServo](INFO): Powering down
2019-07-09T17:36:11.668Z,1562693771.668 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-07-09T17:36:11.669Z,1562693771.669 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-07-09T17:36:11.669Z,1562693771.669 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-07-09T17:36:11.669Z,1562693771.669 [CBIT](DEBUG): Powering off loads.
2019-07-09T17:36:11.681Z,1562693771.681 [CBIT](DEBUG): Disabling WDT.
2019-07-09T17:36:11.693Z,1562693771.693 [CBIT](DEBUG): Opening all GF detection circuits.
2019-07-09T17:36:11.693Z,1562693771.693 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.734Z,1562693771.734 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.743Z,1562693771.743 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.793Z,1562693771.793 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.796Z,1562693771.796 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.875Z,1562693771.875 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-09T17:36:11.930Z,1562693771.930 [logger ThreadHandler](INFO): Thread cancelled.