2019-05-30T23:44:20.562Z,1559259860.562 [Supervisor](DEBUG): Initializing supervisor.
2019-05-30T23:44:20.565Z,1559259860.565 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-30T23:44:20.565Z,1559259860.565 [SyncHandler](INFO): Protected caller Thread ID is 972
2019-05-30T23:44:20.566Z,1559259860.566 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-30T23:44:20.567Z,1559259860.567 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-30T23:44:20.567Z,1559259860.567 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 973
2019-05-30T23:44:20.570Z,1559259860.570 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-30T23:44:20.582Z,1559259860.582 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-30T23:44:20.582Z,1559259860.582 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-30T23:44:20.583Z,1559259860.583 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 974
2019-05-30T23:44:20.584Z,1559259860.584 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-30T23:44:20.585Z,1559259860.585 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-30T23:44:20.585Z,1559259860.585 [logger ThreadHandler](INFO): Protected caller Thread ID is 975
2019-05-30T23:44:20.587Z,1559259860.587 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-30T23:44:20.587Z,1559259860.587 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-30T23:44:20.589Z,1559259860.589 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-30T23:44:21.007Z,1559259861.007 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-30T23:44:21.008Z,1559259861.008 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-30T23:44:21.105Z,1559259861.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-30T23:44:21.106Z,1559259861.106 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-30T23:44:21.437Z,1559259861.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-30T23:44:21.437Z,1559259861.437 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-30T23:44:21.656Z,1559259861.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-30T23:44:21.656Z,1559259861.656 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-30T23:44:21.846Z,1559259861.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-30T23:44:21.847Z,1559259861.847 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-30T23:44:22.299Z,1559259862.299 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-30T23:44:22.300Z,1559259862.300 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-30T23:44:22.508Z,1559259862.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-30T23:44:22.509Z,1559259862.509 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-30T23:44:22.653Z,1559259862.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-30T23:44:22.654Z,1559259862.654 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-30T23:44:22.847Z,1559259862.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-30T23:44:22.847Z,1559259862.847 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-30T23:44:22.942Z,1559259862.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-30T23:44:22.943Z,1559259862.943 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-30T23:44:23.262Z,1559259863.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-30T23:44:23.263Z,1559259863.263 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-30T23:44:23.343Z,1559259863.343 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-30T23:44:23.445Z,1559259863.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-30T23:44:23.446Z,1559259863.446 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-30T23:44:24.021Z,1559259864.021 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-30T23:44:24.021Z,1559259864.021 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-30T23:44:24.406Z,1559259864.406 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-30T23:44:24.408Z,1559259864.408 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-30T23:44:24.409Z,1559259864.409 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-30T23:44:24.616Z,1559259864.616 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-30T23:44:24.715Z,1559259864.715 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-30T23:44:24.812Z,1559259864.812 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-30T23:44:25.037Z,1559259865.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-30T23:44:25.037Z,1559259865.037 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-30T23:44:25.122Z,1559259865.122 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-30T23:44:25.215Z,1559259865.215 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-30T23:44:25.311Z,1559259865.311 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-30T23:44:25.393Z,1559259865.393 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-30T23:44:25.500Z,1559259865.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-30T23:44:25.669Z,1559259865.669 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-30T23:44:25.799Z,1559259865.799 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-30T23:44:25.814Z,1559259865.814 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-30T23:44:26.180Z,1559259866.180 [AHRS_M2] Loaded
2019-05-30T23:44:26.180Z,1559259866.180 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-30T23:44:26.252Z,1559259866.252 [DataOverHttps] Loaded
2019-05-30T23:44:26.252Z,1559259866.252 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-30T23:44:26.253Z,1559259866.253 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075A4E0
2019-05-30T23:44:26.254Z,1559259866.254 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1054
2019-05-30T23:44:26.267Z,1559259866.267 [Depth_Keller] Loaded
2019-05-30T23:44:26.267Z,1559259866.267 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-30T23:44:26.271Z,1559259866.271 [DropWeight] Loaded
2019-05-30T23:44:26.272Z,1559259866.272 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-30T23:44:26.327Z,1559259866.327 [DUSBL_Hydroid] Loaded
2019-05-30T23:44:26.328Z,1559259866.328 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-30T23:44:26.367Z,1559259866.367 [Micromodem] Loaded
2019-05-30T23:44:26.367Z,1559259866.367 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-30T23:44:26.463Z,1559259866.463 [NAL9602] Loaded
2019-05-30T23:44:26.464Z,1559259866.464 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-30T23:44:26.479Z,1559259866.479 [Onboard] Loaded
2019-05-30T23:44:26.479Z,1559259866.479 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-30T23:44:26.485Z,1559259866.485 [PowerOnly] Loaded
2019-05-30T23:44:26.485Z,1559259866.485 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-30T23:44:26.492Z,1559259866.492 [Radio_Surface] Loaded
2019-05-30T23:44:26.492Z,1559259866.492 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-30T23:44:26.493Z,1559259866.493 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078A4E0
2019-05-30T23:44:26.493Z,1559259866.493 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1055
2019-05-30T23:44:26.537Z,1559259866.537 [RDI_Pathfinder] Loaded
2019-05-30T23:44:26.537Z,1559259866.537 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-30T23:44:28.477Z,1559259868.477 [BPC1] Loaded
2019-05-30T23:44:28.477Z,1559259868.477 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-30T23:44:28.477Z,1559259868.477 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-30T23:44:28.478Z,1559259868.478 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-30T23:44:28.491Z,1559259868.491 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-30T23:44:28.491Z,1559259868.491 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-30T23:44:28.594Z,1559259868.594 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-30T23:44:28.595Z,1559259868.595 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-30T23:44:28.615Z,1559259868.615 [NavChart] Loaded
2019-05-30T23:44:28.615Z,1559259868.615 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-30T23:44:28.619Z,1559259868.619 [UniversalFixResidualReporter] Loaded
2019-05-30T23:44:28.619Z,1559259868.619 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-30T23:44:28.620Z,1559259868.620 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-30T23:44:28.620Z,1559259868.620 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-30T23:44:28.726Z,1559259868.726 [BuoyancyServo] Loaded
2019-05-30T23:44:28.726Z,1559259868.726 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-30T23:44:28.741Z,1559259868.741 [ElevatorServo] Loaded
2019-05-30T23:44:28.742Z,1559259868.742 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-30T23:44:28.756Z,1559259868.756 [MassServo] Loaded
2019-05-30T23:44:28.757Z,1559259868.757 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-30T23:44:28.772Z,1559259868.772 [RudderServo] Loaded
2019-05-30T23:44:28.772Z,1559259868.772 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-30T23:44:28.786Z,1559259868.786 [ThrusterServo] Loaded
2019-05-30T23:44:28.786Z,1559259868.786 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-30T23:44:28.787Z,1559259868.787 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-30T23:44:28.787Z,1559259868.787 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-30T23:44:29.029Z,1559259869.029 [CTD_NeilBrown] Loaded
2019-05-30T23:44:29.029Z,1559259869.029 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-30T23:44:29.030Z,1559259869.030 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408CC4E0
2019-05-30T23:44:29.030Z,1559259869.030 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1056
2019-05-30T23:44:29.074Z,1559259869.074 [WetLabsSeaOWL_UV_A] Loaded
2019-05-30T23:44:29.074Z,1559259869.074 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-30T23:44:29.075Z,1559259869.075 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0
2019-05-30T23:44:29.076Z,1559259869.076 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1057
2019-05-30T23:44:29.076Z,1559259869.076 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-30T23:44:29.077Z,1559259869.077 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-30T23:44:29.359Z,1559259869.359 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-30T23:44:29.360Z,1559259869.360 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-30T23:44:29.400Z,1559259869.400 [DepthRateCalculator] Loaded
2019-05-30T23:44:29.400Z,1559259869.400 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-30T23:44:29.405Z,1559259869.405 [PitchRateCalculator] Loaded
2019-05-30T23:44:29.406Z,1559259869.406 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-30T23:44:29.418Z,1559259869.418 [SpeedCalculator] Loaded
2019-05-30T23:44:29.418Z,1559259869.418 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-30T23:44:29.438Z,1559259869.438 [TempGradientCalculator] Loaded
2019-05-30T23:44:29.439Z,1559259869.439 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-30T23:44:29.444Z,1559259869.444 [YawRateCalculator] Loaded
2019-05-30T23:44:29.445Z,1559259869.445 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-30T23:44:29.484Z,1559259869.484 [ElevatorOffsetCalculator] Loaded
2019-05-30T23:44:29.484Z,1559259869.484 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-30T23:44:29.484Z,1559259869.484 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-30T23:44:29.485Z,1559259869.485 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-30T23:44:29.616Z,1559259869.616 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-30T23:44:29.637Z,1559259869.637 [SBIT] Loaded
2019-05-30T23:44:29.638Z,1559259869.638 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-30T23:44:29.639Z,1559259869.639 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-30T23:44:29.650Z,1559259869.650 [IBIT] Loaded
2019-05-30T23:44:29.650Z,1559259869.650 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-30T23:44:29.653Z,1559259869.653 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-30T23:44:29.789Z,1559259869.789 [CBIT] Loaded
2019-05-30T23:44:29.790Z,1559259869.790 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-30T23:44:29.790Z,1559259869.790 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-30T23:44:29.791Z,1559259869.791 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-30T23:44:29.869Z,1559259869.869 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-30T23:44:29.870Z,1559259869.870 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-30T23:44:29.965Z,1559259869.965 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-30T23:44:29.965Z,1559259869.965 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-30T23:44:30.029Z,1559259870.029 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-30T23:44:30.112Z,1559259870.112 [VerticalControl] Loaded
2019-05-30T23:44:30.112Z,1559259870.112 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-30T23:44:30.113Z,1559259870.113 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-30T23:44:30.170Z,1559259870.170 [HorizontalControl] Loaded
2019-05-30T23:44:30.170Z,1559259870.170 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-30T23:44:30.171Z,1559259870.171 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-30T23:44:30.172Z,1559259870.172 [SpeedControl] Loaded
2019-05-30T23:44:30.173Z,1559259870.173 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-30T23:44:30.173Z,1559259870.173 [LoopControl](DEBUG): Construct LoopControl.
2019-05-30T23:44:30.174Z,1559259870.174 [LoopControl] Loaded
2019-05-30T23:44:30.174Z,1559259870.174 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-30T23:44:30.174Z,1559259870.174 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-30T23:44:30.175Z,1559259870.175 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-30T23:44:30.201Z,1559259870.201 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-30T23:44:30.205Z,1559259870.205 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-30T23:44:30.205Z,1559259870.205 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-30T23:44:30.212Z,1559259870.212 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-30T23:44:30.213Z,1559259870.213 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD54E0
2019-05-30T23:44:30.214Z,1559259870.214 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1058
2019-05-30T23:44:30.218Z,1559259870.218 [Supervisor](INFO): Main Thread ID is 802
2019-05-30T23:44:30.218Z,1559259870.218 [Supervisor](DEBUG): Running supervisor.
2019-05-30T23:44:30.219Z,1559259870.219 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1059
2019-05-30T23:44:30.221Z,1559259870.221 [controlThread ThreadHandler](INFO): Handler Thread ID is 1060
2019-05-30T23:44:30.222Z,1559259870.222 [controlThread](DEBUG): Initializing ControlThread
2019-05-30T23:44:30.228Z,1559259870.228 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-30T23:44:30.228Z,1559259870.228 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-30T23:44:30.229Z,1559259870.229 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-30T23:44:30.230Z,1559259870.230 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-30T23:44:30.230Z,1559259870.230 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-30T23:44:30.230Z,1559259870.230 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-30T23:44:30.231Z,1559259870.231 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-30T23:44:30.231Z,1559259870.231 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-30T23:44:30.232Z,1559259870.232 [SBIT](INFO): Initialize SBIT Component.
2019-05-30T23:44:30.232Z,1559259870.232 [SBIT](IMPORTANT): git: 2019-05-29
2019-05-30T23:44:30.232Z,1559259870.232 [SBIT](INFO): git hash: 3a408d161d85e02f941062c72493668314c507d3
2019-05-30T23:44:30.233Z,1559259870.233 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-30T23:44:30.234Z,1559259870.234 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-30T23:44:30.235Z,1559259870.235 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-05-30T23:44:30.235Z,1559259870.235 [IBIT](INFO): Initialize IBIT Component.
2019-05-30T23:44:30.236Z,1559259870.236 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-30T23:44:30.237Z,1559259870.237 [logger ThreadHandler](INFO): Handler Thread ID is 1061
2019-05-30T23:44:30.249Z,1559259870.249 [CBIT](DEBUG): Initialized mux pins.
2019-05-30T23:44:30.249Z,1559259870.249 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-30T23:44:30.257Z,1559259870.257 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1062
2019-05-30T23:44:30.258Z,1559259870.258 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-30T23:44:30.269Z,1559259870.269 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1063
2019-05-30T23:44:30.273Z,1559259870.273 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-30T23:44:30.273Z,1559259870.273 [CBIT](DEBUG): Initializing heartbeat.
2019-05-30T23:44:30.281Z,1559259870.281 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1064
2019-05-30T23:44:30.282Z,1559259870.282 [CTD_NeilBrown](INFO): Powering down
2019-05-30T23:44:30.309Z,1559259870.309 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1065
2019-05-30T23:44:30.310Z,1559259870.310 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T23:44:30.341Z,1559259870.341 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1066
2019-05-30T23:44:30.345Z,1559259870.345 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-30T23:44:30.345Z,1559259870.345 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-30T23:44:30.345Z,1559259870.345 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-30T23:44:30.345Z,1559259870.345 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-30T23:44:30.346Z,1559259870.346 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-30T23:44:30.346Z,1559259870.346 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-30T23:44:30.346Z,1559259870.346 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-30T23:44:30.346Z,1559259870.346 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-30T23:44:30.346Z,1559259870.346 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-30T23:44:30.347Z,1559259870.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-30T23:44:30.347Z,1559259870.347 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-30T23:44:30.347Z,1559259870.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-30T23:44:30.347Z,1559259870.347 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-30T23:44:30.347Z,1559259870.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-30T23:44:30.348Z,1559259870.348 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-30T23:44:30.348Z,1559259870.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-30T23:44:30.348Z,1559259870.348 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-30T23:44:30.348Z,1559259870.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-30T23:44:30.381Z,1559259870.381 [CBIT](DEBUG): Backplane powered.
2019-05-30T23:44:30.381Z,1559259870.381 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-30T23:44:30.383Z,1559259870.383 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-30T23:44:30.383Z,1559259870.383 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-30T23:44:30.384Z,1559259870.384 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-30T23:44:30.385Z,1559259870.385 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-30T23:44:30.394Z,1559259870.394 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T23:44:30.417Z,1559259870.417 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

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

    </Aggregate>

</Mission>


2019-05-30T23:44:30.418Z,1559259870.418 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-30T23:44:30.472Z,1559259870.472 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-30T23:44:30.493Z,1559259870.493 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-30T23:44:30.495Z,1559259870.495 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T23:44:30.529Z,1559259870.529 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-30T23:44:30.532Z,1559259870.532 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-30T23:44:30.553Z,1559259870.553 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-30T23:44:30.556Z,1559259870.556 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2019-05-30T23:44:30.577Z,1559259870.577 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-30T23:44:30.582Z,1559259870.582 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-30T23:44:30.618Z,1559259870.618 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-05-30T23:44:30.619Z,1559259870.619 [DUSBL_Hydroid](INFO): Powering up
2019-05-30T23:44:30.619Z,1559259870.619 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-30T23:44:30.673Z,1559259870.673 [Radio_Surface](INFO): Powering up
2019-05-30T23:44:30.701Z,1559259870.701 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-30T23:44:30.716Z,1559259870.716 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:44:30.725Z,1559259870.725 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-30T23:44:30.726Z,1559259870.726 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:44:30.733Z,1559259870.733 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-30T23:44:30.734Z,1559259870.734 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:44:30.741Z,1559259870.741 [MassServo](DEBUG): Initializing MassServo.
2019-05-30T23:44:30.742Z,1559259870.742 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:44:30.749Z,1559259870.749 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T23:44:30.750Z,1559259870.750 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:44:30.758Z,1559259870.758 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-30T23:44:31.002Z,1559259871.002 [Micromodem](INFO): Powering up
2019-05-30T23:44:31.003Z,1559259871.003 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-30T23:44:31.033Z,1559259871.033 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-30T23:44:43.961Z,1559259883.961 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T23:44:47.166Z,1559259887.166 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-05-30T23:44:48.798Z,1559259888.798 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-30T23:44:56.863Z,1559259896.863 [NAL9602](INFO): Powering up NAL9602
2019-05-30T23:44:58.478Z,1559259898.478 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-05-30T23:45:07.771Z,1559259907.771 [NAL9602](INFO): NAL9602 initialized
2019-05-30T23:45:08.597Z,1559259908.597 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:09.819Z,1559259909.819 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-30T23:45:09.823Z,1559259909.823 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T23:45:12.381Z,1559259912.381 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T23:45:12.381Z,1559259912.381 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053016540, -0.1,   0.0,1448.9,  0
2019-05-30T23:45:20.947Z,1559259920.947 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.013273
CHAN A1 (24V): -0.026133
CHAN A2 (12V): -0.006168
CHAN A3 (5V): -0.002037
CHAN B0 (3.3V): 0.000302
CHAN B1 (3.15aV): 0.000223
CHAN B2 (3.15bV): 0.000116
CHAN B3 (GND): 0.001679
OPEN: 0.005807
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T23:45:34.368Z,1559259934.368 [NAL9602](INFO): SBD MO Status=0, MOMSN=5615, MT Status=0, MTMSN=0
2019-05-30T23:45:34.368Z,1559259934.368 [NAL9602](INFO): No messages in MT queue
2019-05-30T23:45:35.193Z,1559259935.193 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:38.025Z,1559259938.025 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:41.253Z,1559259941.253 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:44.081Z,1559259944.081 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:47.309Z,1559259947.309 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:50.137Z,1559259950.137 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:53.041Z,1559259953.041 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:56.277Z,1559259956.277 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:45:59.101Z,1559259959.101 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:02.337Z,1559259962.337 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:03.190Z,1559259963.190 [SBIT](IMPORTANT): SBIT PASSED
2019-05-30T23:46:03.274Z,1559259963.274 [CommandLine](IMPORTANT): got command configSet list
2019-05-30T23:46:03.274Z,1559259963.274 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-30T23:46:03.275Z,1559259963.275 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-30T23:46:03.275Z,1559259963.275 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;

2019-05-30T23:46:03.275Z,1559259963.275 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=90 count;

2019-05-30T23:46:03.275Z,1559259963.275 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;

2019-05-30T23:46:03.276Z,1559259963.276 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;

2019-05-30T23:46:03.277Z,1559259963.277 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-30T23:46:03.277Z,1559259963.277 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;

2019-05-30T23:46:03.277Z,1559259963.277 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-05-30T23:46:03.558Z,1559259963.558 [MissionManager](IMPORTANT): Started mission Startup
2019-05-30T23:46:03.558Z,1559259963.558 [Startup] Running Loop=1
2019-05-30T23:46:03.558Z,1559259963.558 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-30T23:46:03.558Z,1559259963.558 [Startup:A.GoToSurface] Running Loop=1
2019-05-30T23:46:03.558Z,1559259963.558 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T23:46:03.559Z,1559259963.559 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T23:46:03.559Z,1559259963.559 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T23:46:03.560Z,1559259963.560 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T23:46:03.560Z,1559259963.560 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T23:46:03.560Z,1559259963.560 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T23:46:03.562Z,1559259963.562 [Startup:StartupSatComms] Running Loop=1
2019-05-30T23:46:03.562Z,1559259963.562 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-30T23:46:03.562Z,1559259963.562 [Startup:StartupSatComms:A] Running Loop=1
2019-05-30T23:46:03.983Z,1559259963.983 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-30T23:46:05.169Z,1559259965.169 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:07.993Z,1559259967.993 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:11.225Z,1559259971.225 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:14.053Z,1559259974.053 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:17.281Z,1559259977.281 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:20.113Z,1559259980.113 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:23.341Z,1559259983.341 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:26.169Z,1559259986.169 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:28.997Z,1559259988.997 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:32.237Z,1559259992.237 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:35.061Z,1559259995.061 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:38.297Z,1559259998.297 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:41.117Z,1559260001.117 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:44.353Z,1559260004.353 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:47.177Z,1559260007.177 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:50.005Z,1559260010.005 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:53.241Z,1559260013.241 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:56.069Z,1559260016.069 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:46:59.313Z,1559260019.313 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:47:02.129Z,1559260022.129 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:47:03.871Z,1559260023.871 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-30T23:46:03.6Z
2019-05-30T23:47:03.871Z,1559260023.871 [Startup:StartupSatComms:A] Stopped
2019-05-30T23:47:03.872Z,1559260023.872 [Startup:StartupSatComms:B] Running Loop=1
2019-05-30T23:47:04.186Z,1559260024.186 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T23:47:04.953Z,1559260024.953 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:47:29.045Z,1559260049.045 [NAL9602](INFO): SBD MO Status=2, MOMSN=5616, MT Status=2, MTMSN=0
2019-05-30T23:47:29.045Z,1559260049.045 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T23:47:29.873Z,1559260049.873 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:47:30.301Z,1559260050.301 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-30T23:47:30.301Z,1559260050.301 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T23:47:30.319Z,1559260050.319 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T23:47:30.846Z,1559260050.846 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T23:47:30.846Z,1559260050.846 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-30T23:47:52.595Z,1559260072.595 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004956
2019-05-30T23:47:54.655Z,1559260074.655 [NAL9602](INFO): SBD MO Status=2, MOMSN=5616, MT Status=2, MTMSN=0
2019-05-30T23:47:54.656Z,1559260074.656 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T23:47:55.473Z,1559260075.473 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:47:58.293Z,1559260078.293 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:47:59.848Z,1559260079.848 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T224933/Courier0018.lzma
2019-05-30T23:48:00.655Z,1559260080.655 [DataOverHttps](INFO): Moved sent file to Logs/20190530T224933/Courier0018.lzma.bak
2019-05-30T23:48:00.656Z,1559260080.656 [DataOverHttps](INFO): SBD MOMSN=11226100
2019-05-30T23:48:01.125Z,1559260081.125 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:03.970Z,1559260083.970 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-30T23:47:03.9Z
2019-05-30T23:48:03.970Z,1559260083.970 [Startup:StartupSatComms:B] Stopped
2019-05-30T23:48:03.971Z,1559260083.971 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-30T23:48:03.971Z,1559260083.971 [Startup:StartupSatComms] Stopped
2019-05-30T23:48:03.971Z,1559260083.971 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-30T23:48:03.971Z,1559260083.971 [Startup](INFO): Completed Startup
2019-05-30T23:48:03.972Z,1559260083.972 [MissionManager](INFO): Startup is completed.
2019-05-30T23:48:03.972Z,1559260083.972 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-30T23:48:03.972Z,1559260083.972 [Startup] Stopped
2019-05-30T23:48:03.972Z,1559260083.972 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-30T23:48:03.972Z,1559260083.972 [Startup:A.GoToSurface] Stopped
2019-05-30T23:48:03.972Z,1559260083.972 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T23:48:04.353Z,1559260084.353 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:04.378Z,1559260084.378 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T23:48:04.378Z,1559260084.378 [Default] Running Loop=1
2019-05-30T23:48:04.378Z,1559260084.378 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T23:48:04.378Z,1559260084.378 [Default:B.GoToSurface] Running Loop=1
2019-05-30T23:48:04.378Z,1559260084.378 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T23:48:04.379Z,1559260084.379 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T23:48:04.379Z,1559260084.379 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T23:48:04.379Z,1559260084.379 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T23:48:04.380Z,1559260084.380 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T23:48:04.380Z,1559260084.380 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T23:48:04.380Z,1559260084.380 [Default:A.Wait] Running Loop=1
2019-05-30T23:48:04.380Z,1559260084.380 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T23:48:07.181Z,1559260087.181 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:10.013Z,1559260090.013 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:12.168Z,1559260092.168 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190530T224933/Courier0021.lzma
2019-05-30T23:48:12.974Z,1559260092.974 [DataOverHttps](INFO): Moved sent file to Logs/20190530T224933/Courier0021.lzma.bak
2019-05-30T23:48:12.974Z,1559260092.974 [DataOverHttps](INFO): SBD MOMSN=11226102
2019-05-30T23:48:13.241Z,1559260093.241 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:16.073Z,1559260096.073 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:17.698Z,1559260097.698 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T23:48:17.698Z,1559260097.698 [Default:A.Wait] Stopped
2019-05-30T23:48:17.698Z,1559260097.698 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T23:48:18.112Z,1559260098.112 [Default:CheckIn] Running Loop=1
2019-05-30T23:48:18.112Z,1559260098.112 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T23:48:18.112Z,1559260098.112 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T23:48:18.526Z,1559260098.526 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-30T23:48:19.301Z,1559260099.301 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:22.138Z,1559260102.138 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:25.361Z,1559260105.361 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:28.193Z,1559260108.193 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:31.017Z,1559260111.017 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:33.441Z,1559260113.441 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:36.269Z,1559260116.269 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:39.501Z,1559260119.501 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:42.335Z,1559260122.335 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:45.161Z,1559260125.161 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:47.989Z,1559260127.989 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:51.221Z,1559260131.221 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:54.049Z,1559260134.049 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:48:57.281Z,1559260137.281 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:00.105Z,1559260140.105 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:03.341Z,1559260143.341 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:06.169Z,1559260146.169 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:09.397Z,1559260149.397 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:12.229Z,1559260152.229 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:15.457Z,1559260155.457 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:18.301Z,1559260158.301 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:21.521Z,1559260161.521 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:24.353Z,1559260164.353 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:27.581Z,1559260167.581 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:30.413Z,1559260170.413 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:30.932Z,1559260170.932 [CommandLine](IMPORTANT): got command get latitude
2019-05-30T23:49:30.933Z,1559260170.933 [CommandLine](FAULT): Element has no value
2019-05-30T23:49:33.237Z,1559260173.237 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:36.065Z,1559260176.065 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:39.297Z,1559260179.297 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:42.125Z,1559260182.125 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:45.353Z,1559260185.353 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:47.379Z,1559260187.379 [CommandLine](IMPORTANT): got command show variable fastFix
2019-05-30T23:49:48.185Z,1559260188.185 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:50.417Z,1559260190.417 [CommandLine](IMPORTANT): got command show variable fast
2019-05-30T23:49:50.446Z,1559260190.446 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpCoefficient (none)
2019-05-30T23:49:50.447Z,1559260190.447 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth (meter)
2019-05-30T23:49:50.452Z,1559260190.452 [CommandLine](IMPORTANT): NAL9602.fastGPSFix (bool)
2019-05-30T23:49:51.417Z,1559260191.417 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:54.257Z,1559260194.257 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:57.473Z,1559260197.473 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:49:58.944Z,1559260198.944 [CommandLine](IMPORTANT): got command get NAL9602.fastGPSFix
2019-05-30T23:49:58.949Z,1559260198.949 [CommandLine](IMPORTANT): NAL9602.fastGPSFix 1 bool
2019-05-30T23:50:00.305Z,1559260200.305 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:03.541Z,1559260203.541 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:06.361Z,1559260206.361 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:09.593Z,1559260209.593 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:12.425Z,1559260212.425 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:15.257Z,1559260215.257 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:18.081Z,1559260218.081 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:21.313Z,1559260221.313 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:24.141Z,1559260224.141 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:27.369Z,1559260227.369 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:30.209Z,1559260230.209 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:31.421Z,1559260231.421 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-05-30T23:50:31.421Z,1559260231.421 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T23:50:31.436Z,1559260231.436 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T23:50:31.857Z,1559260231.857 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T23:50:31.857Z,1559260231.857 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-05-30T23:50:31.927Z,1559260231.927 [CommandLine](IMPORTANT): got command ibit
2019-05-30T23:50:32.368Z,1559260232.368 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-05-30T23:50:32.373Z,1559260232.373 [IBIT](IMPORTANT): Beginning control surface checks.
2019-05-30T23:50:32.376Z,1559260232.376 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T23:50:33.433Z,1559260233.433 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:36.261Z,1559260236.261 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:39.493Z,1559260239.493 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:41.676Z,1559260241.676 [CommandLine](IMPORTANT): got command failComponent
2019-05-30T23:50:41.677Z,1559260241.677 [CommandLine](IMPORTANT): Failed components:
2019-05-30T23:50:41.677Z,1559260241.677 [CommandLine](IMPORTANT): No failed Components.
2019-05-30T23:50:42.321Z,1559260242.321 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:43.171Z,1559260243.171 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.013320
CHAN A1 (24V): -0.026059
CHAN A2 (12V): -0.006171
CHAN A3 (5V): -0.001613
CHAN B0 (3.3V): -0.000113
CHAN B1 (3.15aV): 0.000127
CHAN B2 (3.15bV): 0.000405
CHAN B3 (GND): 0.001850
OPEN: 0.006042
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T23:50:45.549Z,1559260245.549 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:48.377Z,1559260248.377 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:51.209Z,1559260251.209 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:54.437Z,1559260254.437 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:50:55.266Z,1559260255.266 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T23:50:55.266Z,1559260255.266 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053017001721,35.0, -0.1,   0.,  0
2019-05-30T23:50:57.275Z,1559260257.275 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:00.097Z,1559260260.097 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:03.329Z,1559260263.329 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:06.153Z,1559260266.153 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:09.385Z,1559260269.385 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:12.213Z,1559260272.213 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:15.449Z,1559260275.449 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:18.273Z,1559260278.273 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:21.505Z,1559260281.505 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:24.333Z,1559260284.333 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:27.565Z,1559260287.565 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:30.393Z,1559260290.393 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:33.225Z,1559260293.225 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:36.059Z,1559260296.059 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:39.281Z,1559260299.281 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:42.113Z,1559260302.113 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:45.349Z,1559260305.349 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:48.173Z,1559260308.173 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:51.401Z,1559260311.401 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:54.233Z,1559260314.233 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:51:57.461Z,1559260317.461 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:00.289Z,1559260320.289 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:03.525Z,1559260323.525 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:06.353Z,1559260326.353 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:09.585Z,1559260329.585 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:12.417Z,1559260332.417 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:15.241Z,1559260335.241 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:18.069Z,1559260338.069 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:21.301Z,1559260341.301 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:23.355Z,1559260343.355 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2019-05-30T23:52:23.803Z,1559260343.803 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2019-05-30T23:52:24.129Z,1559260344.129 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:24.174Z,1559260344.174 [BPC1](ERROR): Battery stick #38 (s/n: 015C) reported OVER_TEMP_ALARM. Status code: 0x1717.
2019-05-30T23:52:24.174Z,1559260344.174 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2019-05-30T23:52:24.177Z,1559260344.177 [BPC1](INFO): Received data from all battery sticks.
2019-05-30T23:52:24.188Z,1559260344.188 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-05-30T23:52:24.189Z,1559260344.189 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-05-30T23:52:24.189Z,1559260344.189 [IBIT](IMPORTANT): Pressure:9.234485 PSI
2019-05-30T23:52:24.190Z,1559260344.190 [IBIT](IMPORTANT): Humidity:7.727994 %
2019-05-30T23:52:24.564Z,1559260344.564 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-05-30T23:52:24.564Z,1559260344.564 [IBIT](IMPORTANT): buoyancyNeutral: 190.000000 cc
2019-05-30T23:52:24.565Z,1559260344.565 [IBIT](IMPORTANT): massDefault: 0.500000 cm
2019-05-30T23:52:24.565Z,1559260344.565 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2019-05-30T23:52:24.565Z,1559260344.565 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2019-05-30T23:52:24.565Z,1559260344.565 [IBIT](IMPORTANT): IBIT FAILED
2019-05-30T23:52:27.357Z,1559260347.357 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:30.185Z,1559260350.185 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:33.417Z,1559260353.417 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:36.248Z,1559260356.248 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:39.481Z,1559260359.481 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:42.309Z,1559260362.309 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:45.537Z,1559260365.537 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:48.365Z,1559260368.365 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:51.197Z,1559260371.197 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:54.021Z,1559260374.021 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:52:57.253Z,1559260377.253 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:00.085Z,1559260380.085 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:03.317Z,1559260383.317 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:06.141Z,1559260386.141 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:09.377Z,1559260389.377 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:12.205Z,1559260392.205 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:15.437Z,1559260395.437 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:16.187Z,1559260396.187 [CommandLine](IMPORTANT): got command show stack
2019-05-30T23:53:16.187Z,1559260396.187 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-30T23:53:16.187Z,1559260396.187 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2019-05-30T23:53:16.188Z,1559260396.188 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2019-05-30T23:53:18.261Z,1559260398.261 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:18.291Z,1559260398.291 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-05-30T23:48:18.1Z
2019-05-30T23:53:18.291Z,1559260398.291 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T23:53:18.291Z,1559260398.291 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T23:53:18.694Z,1559260398.694 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T23:53:21.489Z,1559260401.489 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:24.198Z,1559260404.198 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190530T233237/Courier0000.lzma
2019-05-30T23:53:24.317Z,1559260404.317 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:25.002Z,1559260405.002 [DataOverHttps](INFO): Moved sent file to Logs/20190530T233237/Courier0000.lzma.bak
2019-05-30T23:53:25.002Z,1559260405.002 [DataOverHttps](INFO): SBD MOMSN=11226130
2019-05-30T23:53:27.149Z,1559260407.149 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:30.377Z,1559260410.377 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:32.427Z,1559260412.427 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-05-30T23:53:32.427Z,1559260412.427 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T23:53:32.437Z,1559260412.437 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T23:53:32.822Z,1559260412.822 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T23:53:32.822Z,1559260412.822 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-05-30T23:53:33.209Z,1559260413.209 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:36.037Z,1559260416.037 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:37.256Z,1559260417.256 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190530T233237/Courier0004.lzma
2019-05-30T23:53:38.062Z,1559260418.062 [DataOverHttps](INFO): Moved sent file to Logs/20190530T233237/Courier0004.lzma.bak
2019-05-30T23:53:38.062Z,1559260418.062 [DataOverHttps](INFO): SBD MOMSN=11226137
2019-05-30T23:53:39.265Z,1559260419.265 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:42.093Z,1559260422.093 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:45.325Z,1559260425.325 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:48.153Z,1559260428.153 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:49.132Z,1559260429.132 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190530T233803/Courier0004.lzma
2019-05-30T23:53:49.938Z,1559260429.938 [DataOverHttps](INFO): Moved sent file to Logs/20190530T233803/Courier0004.lzma.bak
2019-05-30T23:53:49.938Z,1559260429.938 [DataOverHttps](INFO): SBD MOMSN=11226146
2019-05-30T23:53:51.385Z,1559260431.385 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:54.237Z,1559260434.237 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:57.045Z,1559260437.045 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:53:58.281Z,1559260438.281 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T23:53:58.281Z,1559260438.281 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 308.53, 307.03, 302.54
2019-05-30T23:53:59.912Z,1559260439.912 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T23:53:59.913Z,1559260439.913 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 323.50, 295.05, 304.04,

2019-05-30T23:54:00.298Z,1559260440.298 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:02.657Z,1559260442.657 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20190530T234420/Courier0004.lzma
2019-05-30T23:54:03.105Z,1559260443.105 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:03.462Z,1559260443.462 [DataOverHttps](INFO): Moved sent file to Logs/20190530T234420/Courier0004.lzma.bak
2019-05-30T23:54:03.462Z,1559260443.462 [DataOverHttps](INFO): SBD MOMSN=11226149
2019-05-30T23:54:06.337Z,1559260446.337 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:09.165Z,1559260449.165 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:12.409Z,1559260452.409 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:15.225Z,1559260455.225 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:15.747Z,1559260455.747 [DataOverHttps](INFO): Sending 1152 bytes from file Logs/20190530T224933/Express0019.lzma
2019-05-30T23:54:16.634Z,1559260456.634 [DataOverHttps](INFO): Moved sent file to Logs/20190530T224933/Express0019.lzma.bak
2019-05-30T23:54:16.634Z,1559260456.634 [DataOverHttps](INFO): SBD MOMSN=11226152
2019-05-30T23:54:18.057Z,1559260458.057 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:21.285Z,1559260461.285 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:24.113Z,1559260464.113 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:27.345Z,1559260467.345 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:28.412Z,1559260468.412 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190530T224933/Express0022.lzma
2019-05-30T23:54:28.994Z,1559260468.994 [CommandLine](IMPORTANT): got command get latitude
2019-05-30T23:54:28.994Z,1559260468.994 [CommandLine](FAULT): Element has no value
2019-05-30T23:54:29.218Z,1559260469.218 [DataOverHttps](INFO): Moved sent file to Logs/20190530T224933/Express0022.lzma.bak
2019-05-30T23:54:29.218Z,1559260469.218 [DataOverHttps](INFO): SBD MOMSN=11226154
2019-05-30T23:54:30.185Z,1559260470.185 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:33.405Z,1559260473.405 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:36.237Z,1559260476.237 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:38.262Z,1559260478.262 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T23:54:38.262Z,1559260478.262 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-30T23:54:39.065Z,1559260479.065 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:41.056Z,1559260481.056 [DataOverHttps](INFO): Sending 1251 bytes from file Logs/20190530T233237/Express0001.lzma
2019-05-30T23:54:42.262Z,1559260482.262 [DataOverHttps](INFO): Moved sent file to Logs/20190530T233237/Express0001.lzma.bak
2019-05-30T23:54:42.262Z,1559260482.262 [DataOverHttps](INFO): SBD MOMSN=11226156
2019-05-30T23:54:42.297Z,1559260482.297 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:45.129Z,1559260485.129 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:48.357Z,1559260488.357 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:51.181Z,1559260491.181 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:54.044Z,1559260494.044 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190530T233237/Express0005.lzma
2019-05-30T23:54:54.413Z,1559260494.413 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:54.850Z,1559260494.850 [DataOverHttps](INFO): Moved sent file to Logs/20190530T233237/Express0005.lzma.bak
2019-05-30T23:54:54.850Z,1559260494.850 [DataOverHttps](INFO): SBD MOMSN=11226195
2019-05-30T23:54:57.245Z,1559260497.245 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:54:59.271Z,1559260499.271 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T23:54:59.271Z,1559260499.271 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,299.54, 322.00,   0.00, 292.06
2019-05-30T23:55:00.069Z,1559260500.069 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:55:03.313Z,1559260503.313 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:55:06.129Z,1559260506.129 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:55:07.154Z,1559260507.154 [DataOverHttps](INFO): Sending 991 bytes from file Logs/20190530T233803/Express0001.lzma
2019-05-30T23:55:07.958Z,1559260507.958 [DataOverHttps](INFO): Moved sent file to Logs/20190530T233803/Express0001.lzma.bak
2019-05-30T23:55:07.958Z,1559260507.958 [DataOverHttps](INFO): SBD MOMSN=11226197
2019-05-30T23:55:09.355Z,1559260509.355 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-05-30T23:55:09.355Z,1559260509.355 [NAL9602] Data Fault, FailCount= 1
2019-05-30T23:55:09.355Z,1559260509.355 [NAL9602](ERROR): Data Fault
2019-05-30T23:55:09.395Z,1559260509.395 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-30T23:55:09.773Z,1559260509.773 [NAL9602](INFO): Powering down
2019-05-30T23:55:10.622Z,1559260510.622 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-30T23:55:10.623Z,1559260510.623 [NAL9602] No Fault, FailCount= 1
2019-05-30T23:55:19.709Z,1559260519.709 [DataOverHttps](INFO): Sending 637 bytes from file Logs/20190530T233803/Express0005.lzma
2019-05-30T23:55:20.514Z,1559260520.514 [DataOverHttps](INFO): Moved sent file to Logs/20190530T233803/Express0005.lzma.bak
2019-05-30T23:55:20.514Z,1559260520.514 [DataOverHttps](INFO): SBD MOMSN=11226225
2019-05-30T23:55:32.759Z,1559260532.759 [DataOverHttps](INFO): Sending 1481 bytes from file Logs/20190530T234420/Express0001.lzma
2019-05-30T23:55:32.989Z,1559260532.989 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2019-05-30T23:55:32.989Z,1559260532.989 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-05-30T23:55:32.989Z,1559260532.989 [RDI_Pathfinder](ERROR): Communications Fault
2019-05-30T23:55:32.990Z,1559260532.990 [RDI_Pathfinder](ERROR): Failed to parse:
2019-05-30T23:55:33.011Z,1559260533.011 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-05-30T23:55:33.281Z,1559260533.281 [RDI_Pathfinder](INFO): Powering down
2019-05-30T23:55:33.594Z,1559260533.594 [DataOverHttps](INFO): Moved sent file to Logs/20190530T234420/Express0001.lzma.bak
2019-05-30T23:55:33.595Z,1559260533.595 [DataOverHttps](INFO): SBD MOMSN=11226247
2019-05-30T23:55:34.091Z,1559260534.091 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-05-30T23:55:34.091Z,1559260534.091 [RDI_Pathfinder] No Fault, FailCount= 1
2019-05-30T23:55:37.735Z,1559260537.735 [CommandLine](IMPORTANT): got command failComponent
2019-05-30T23:55:37.735Z,1559260537.735 [CommandLine](IMPORTANT): Failed components:
2019-05-30T23:55:37.735Z,1559260537.735 [CommandLine](IMPORTANT): No failed Components.
2019-05-30T23:55:40.051Z,1559260540.051 [NAL9602](INFO): Powering up NAL9602
2019-05-30T23:55:44.868Z,1559260544.868 [DataOverHttps](INFO): Sending 2149 bytes from file Logs/20190530T234420/Express0005.lzma
2019-05-30T23:55:45.670Z,1559260545.670 [DataOverHttps](INFO): Moved sent file to Logs/20190530T234420/Express0005.lzma.bak
2019-05-30T23:55:45.670Z,1559260545.670 [DataOverHttps](INFO): SBD MOMSN=11226274
2019-05-30T23:55:46.958Z,1559260546.958 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T23:55:46.958Z,1559260546.958 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T23:55:46.958Z,1559260546.958 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T23:55:47.353Z,1559260547.353 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T23:55:50.959Z,1559260550.959 [NAL9602](INFO): NAL9602 initialized
2019-05-30T23:55:51.785Z,1559260551.785 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:55:54.225Z,1559260554.225 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:55:57.469Z,1559260557.469 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:00.277Z,1559260560.277 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:03.505Z,1559260563.505 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:06.333Z,1559260566.333 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:09.161Z,1559260569.161 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:11.989Z,1559260571.989 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:15.229Z,1559260575.229 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:18.049Z,1559260578.049 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:21.293Z,1559260581.293 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:24.109Z,1559260584.109 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:27.341Z,1559260587.341 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:30.169Z,1559260590.169 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:33.413Z,1559260593.413 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:33.459Z,1559260593.459 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-05-30T23:56:33.459Z,1559260593.459 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T23:56:33.470Z,1559260593.470 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T23:56:33.866Z,1559260593.866 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T23:56:33.866Z,1559260593.866 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-05-30T23:56:36.229Z,1559260596.229 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:39.465Z,1559260599.465 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:42.293Z,1559260602.293 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:45.121Z,1559260605.121 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:47.945Z,1559260607.945 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:51.181Z,1559260611.181 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:54.005Z,1559260614.005 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:56:57.245Z,1559260617.245 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:00.069Z,1559260620.069 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:03.301Z,1559260623.301 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:06.129Z,1559260626.129 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:09.365Z,1559260629.365 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:12.185Z,1559260632.185 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:15.429Z,1559260635.429 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:18.245Z,1559260638.245 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:21.485Z,1559260641.485 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:24.309Z,1559260644.309 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:27.133Z,1559260647.133 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:29.973Z,1559260649.973 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:33.197Z,1559260653.197 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:36.025Z,1559260656.025 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:39.253Z,1559260659.253 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:42.085Z,1559260662.085 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:45.313Z,1559260665.313 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:48.141Z,1559260668.141 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:51.374Z,1559260671.374 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:54.205Z,1559260674.205 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:57.433Z,1559260677.433 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:57:57.471Z,1559260677.471 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T23:57:57.472Z,1559260677.472 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,   +67,  378,A
2019-05-30T23:58:00.265Z,1559260680.265 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:03.493Z,1559260683.493 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:06.321Z,1559260686.321 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:09.149Z,1559260689.149 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:11.977Z,1559260691.977 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:15.209Z,1559260695.209 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:18.037Z,1559260698.037 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:21.277Z,1559260701.277 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:24.097Z,1559260704.097 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:27.337Z,1559260707.337 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:30.157Z,1559260710.157 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:33.389Z,1559260713.389 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:36.217Z,1559260716.217 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:39.449Z,1559260719.449 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:42.289Z,1559260722.289 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:45.509Z,1559260725.509 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:48.337Z,1559260728.337 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:51.178Z,1559260731.178 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:54.401Z,1559260734.401 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:58:57.237Z,1559260737.237 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:00.053Z,1559260740.053 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:03.289Z,1559260743.289 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:06.113Z,1559260746.113 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:09.345Z,1559260749.345 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:12.173Z,1559260752.173 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:15.425Z,1559260755.425 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:18.237Z,1559260758.237 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:21.469Z,1559260761.469 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:24.293Z,1559260764.293 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:27.529Z,1559260767.529 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:30.353Z,1559260770.353 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:33.181Z,1559260773.181 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:34.418Z,1559260774.418 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-05-30T23:59:34.418Z,1559260774.418 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T23:59:34.444Z,1559260774.444 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T23:59:34.835Z,1559260774.835 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T23:59:34.835Z,1559260774.835 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-05-30T23:59:36.009Z,1559260776.009 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:39.241Z,1559260779.241 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:42.073Z,1559260782.073 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:45.301Z,1559260785.301 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:48.133Z,1559260788.133 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:51.385Z,1559260791.385 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:54.193Z,1559260794.193 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:59:57.425Z,1559260797.425 [NAL9602](DEBUG): Fix Requested
2019-05-31T00:00:00.253Z,1559260800.253 [NAL9602](DEBUG): Fix Requested
2019-05-31T00:00:03.485Z,1559260803.485 [NAL9602](DEBUG): Fix Requested
2019-05-31T00:00:04.990Z,1559260804.990 [DataOverHttps](IMPORTANT): SBD MTMSN=20190530T235956
2019-05-31T00:00:06.313Z,1559260806.313 [NAL9602](DEBUG): Fix Requested
2019-05-31T00:00:09.137Z,1559260809.137 [NAL9602](DEBUG): Fix Requested
2019-05-31T00:00:10.173Z,1559260810.173 [DataOverHttps](INFO): Received command:restart sys
2019-05-31T00:00:10.201Z,1559260810.201 [CommandLine](IMPORTANT): got command restart system
2019-05-31T00:00:12.373Z,1559260812.373 [NAL9602](DEBUG): Fix Requested
2019-05-31T00:00:12.621Z,1559260812.621 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-31T00:00:12.621Z,1559260812.621 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:12.622Z,1559260812.622 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:12.741Z,1559260812.741 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-31T00:00:12.741Z,1559260812.741 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:12.742Z,1559260812.742 [CommandLine](INFO): Join timeout helper Thread ID is 1139
2019-05-31T00:00:12.742Z,1559260812.742 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-31T00:00:12.742Z,1559260812.742 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:12.743Z,1559260812.743 [NavChartDb](INFO): Join timeout helper Thread ID is 1140
2019-05-31T00:00:13.033Z,1559260813.033 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:13.033Z,1559260813.033 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.049Z,1559260813.049 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-05-31T00:00:13.049Z,1559260813.049 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.049Z,1559260813.049 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1141
2019-05-31T00:00:13.349Z,1559260813.349 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:13.349Z,1559260813.349 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-31T00:00:13.350Z,1559260813.350 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.350Z,1559260813.350 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-31T00:00:13.351Z,1559260813.351 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.351Z,1559260813.351 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1142
2019-05-31T00:00:13.497Z,1559260813.497 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:13.497Z,1559260813.497 [CTD_NeilBrown](INFO): Powering down
2019-05-31T00:00:13.509Z,1559260813.509 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.513Z,1559260813.513 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-31T00:00:13.513Z,1559260813.513 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.513Z,1559260813.513 [Radio_Surface](INFO): Join timeout helper Thread ID is 1143
2019-05-31T00:00:13.753Z,1559260813.753 [Radio_Surface](INFO): Powering down
2019-05-31T00:00:13.754Z,1559260813.754 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:13.754Z,1559260813.754 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.774Z,1559260813.774 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-31T00:00:13.774Z,1559260813.774 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.774Z,1559260813.774 [DataOverHttps](INFO): Join timeout helper Thread ID is 1144
2019-05-31T00:00:13.805Z,1559260813.805 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:13.805Z,1559260813.805 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.813Z,1559260813.813 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-31T00:00:13.814Z,1559260813.814 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.814Z,1559260813.814 [logger](INFO): Join timeout helper Thread ID is 1145
2019-05-31T00:00:13.821Z,1559260813.821 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:13.821Z,1559260813.821 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.833Z,1559260813.833 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-31T00:00:13.834Z,1559260813.834 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.834Z,1559260813.834 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-31T00:00:13.834Z,1559260813.834 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:13.834Z,1559260813.834 [controlThread](INFO): Join timeout helper Thread ID is 1146
2019-05-31T00:00:13.961Z,1559260813.961 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-31T00:00:13.961Z,1559260813.961 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-31T00:00:13.962Z,1559260813.962 [AHRS_M2](INFO): Powering down
2019-05-31T00:00:14.033Z,1559260814.033 [DUSBL_Hydroid](INFO): Powering down
2019-05-31T00:00:14.125Z,1559260814.125 [Micromodem](INFO): Powering down
2019-05-31T00:00:14.221Z,1559260814.221 [NAL9602](INFO): Powering down
2019-05-31T00:00:14.293Z,1559260814.293 [RDI_Pathfinder](INFO): Powering down
2019-05-31T00:00:14.294Z,1559260814.294 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-31T00:00:14.295Z,1559260814.295 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-31T00:00:14.296Z,1559260814.296 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-31T00:00:14.296Z,1559260814.296 [MissionManager](INFO): Uninitializing Mission Default
2019-05-31T00:00:14.296Z,1559260814.296 [Default] Stopped
2019-05-31T00:00:14.296Z,1559260814.296 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-31T00:00:14.296Z,1559260814.296 [Default:B.GoToSurface] Stopped
2019-05-31T00:00:14.296Z,1559260814.296 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-31T00:00:14.297Z,1559260814.297 [Default:CheckIn] Stopped
2019-05-31T00:00:14.297Z,1559260814.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-31T00:00:14.297Z,1559260814.297 [Default:CheckIn:C.Wait] Stopped
2019-05-31T00:00:14.297Z,1559260814.297 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-31T00:00:14.299Z,1559260814.299 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-31T00:00:14.300Z,1559260814.300 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-31T00:00:14.300Z,1559260814.300 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-31T00:00:14.300Z,1559260814.300 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-31T00:00:14.301Z,1559260814.301 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-31T00:00:14.301Z,1559260814.301 [BuoyancyServo](INFO): Powering down
2019-05-31T00:00:14.313Z,1559260814.313 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-31T00:00:14.313Z,1559260814.313 [ElevatorServo](INFO): Powering down
2019-05-31T00:00:14.314Z,1559260814.314 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-31T00:00:14.314Z,1559260814.314 [MassServo](INFO): Powering down
2019-05-31T00:00:14.315Z,1559260814.315 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-31T00:00:14.315Z,1559260814.315 [RudderServo](INFO): Powering down
2019-05-31T00:00:14.316Z,1559260814.316 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-31T00:00:14.316Z,1559260814.316 [ThrusterServo](INFO): Powering down
2019-05-31T00:00:14.317Z,1559260814.317 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-31T00:00:14.317Z,1559260814.317 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-31T00:00:14.317Z,1559260814.317 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-31T00:00:14.318Z,1559260814.318 [CBIT](DEBUG): Powering off loads.
2019-05-31T00:00:14.329Z,1559260814.329 [CBIT](DEBUG): Disabling WDT.
2019-05-31T00:00:14.341Z,1559260814.341 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-31T00:00:14.341Z,1559260814.341 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:14.391Z,1559260814.391 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:14.400Z,1559260814.400 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:14.442Z,1559260814.442 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:14.444Z,1559260814.444 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:14.503Z,1559260814.503 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-31T00:00:14.559Z,1559260814.559 [logger ThreadHandler](INFO): Thread cancelled.