2019-08-19T21:47:19.644Z,1566251239.644 [Supervisor](DEBUG): Initializing supervisor.
2019-08-19T21:47:19.695Z,1566251239.695 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-19T21:47:19.695Z,1566251239.695 [SyncHandler](INFO): Protected caller Thread ID is 4917
2019-08-19T21:47:19.696Z,1566251239.696 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-19T21:47:19.697Z,1566251239.697 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-19T21:47:19.697Z,1566251239.697 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4918
2019-08-19T21:47:19.699Z,1566251239.699 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-19T21:47:19.711Z,1566251239.711 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-19T21:47:19.712Z,1566251239.712 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-19T21:47:19.712Z,1566251239.712 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4919
2019-08-19T21:47:19.713Z,1566251239.713 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-19T21:47:19.714Z,1566251239.714 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-19T21:47:19.715Z,1566251239.715 [logger ThreadHandler](INFO): Protected caller Thread ID is 4920
2019-08-19T21:47:19.717Z,1566251239.717 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-19T21:47:19.717Z,1566251239.717 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-19T21:47:19.720Z,1566251239.720 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-19T21:47:20.214Z,1566251240.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-19T21:47:20.215Z,1566251240.215 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-19T21:47:20.366Z,1566251240.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-19T21:47:20.368Z,1566251240.368 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-19T21:47:20.452Z,1566251240.452 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-19T21:47:20.553Z,1566251240.553 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-19T21:47:20.555Z,1566251240.555 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-19T21:47:20.653Z,1566251240.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-19T21:47:20.655Z,1566251240.655 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-19T21:47:21.038Z,1566251241.038 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-19T21:47:21.039Z,1566251241.039 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-19T21:47:21.144Z,1566251241.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-19T21:47:21.144Z,1566251241.144 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-19T21:47:21.609Z,1566251241.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-19T21:47:21.609Z,1566251241.609 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-19T21:47:21.815Z,1566251241.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-19T21:47:21.816Z,1566251241.816 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-19T21:47:22.124Z,1566251242.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-19T21:47:22.126Z,1566251242.126 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-19T21:47:22.342Z,1566251242.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-19T21:47:22.343Z,1566251242.343 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-19T21:47:22.487Z,1566251242.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-19T21:47:22.488Z,1566251242.488 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-19T21:47:23.146Z,1566251243.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-19T21:47:23.707Z,1566251243.707 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-19T21:47:24.230Z,1566251244.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-19T21:47:24.233Z,1566251244.233 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-19T21:47:24.442Z,1566251244.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-19T21:47:24.444Z,1566251244.444 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2019-08-19T21:47:24.452Z,1566251244.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2019-08-19T21:47:24.527Z,1566251244.527 [Config/vehicle](CRITICAL): Attempting to set a string configuration value to the non-string configuration: DVL_micro.baud
2019-08-19T21:47:24.641Z,1566251244.641 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2019-08-19T21:47:24.727Z,1566251244.727 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2019-08-19T21:47:24.849Z,1566251244.849 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2019-08-19T21:47:24.938Z,1566251244.938 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2019-08-19T21:47:25.168Z,1566251245.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-19T21:47:25.170Z,1566251245.170 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2019-08-19T21:47:25.268Z,1566251245.268 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2019-08-19T21:47:25.379Z,1566251245.379 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2019-08-19T21:47:25.476Z,1566251245.476 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2019-08-19T21:47:25.626Z,1566251245.626 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2019-08-19T21:47:25.729Z,1566251245.729 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2019-08-19T21:47:25.830Z,1566251245.830 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-19T21:47:25.841Z,1566251245.841 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-19T21:47:25.865Z,1566251245.865 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-19T21:47:25.866Z,1566251245.866 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-19T21:47:25.950Z,1566251245.950 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-19T21:47:26.060Z,1566251246.060 [VerticalControl] Loaded
2019-08-19T21:47:26.060Z,1566251246.060 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-19T21:47:26.061Z,1566251246.061 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-19T21:47:26.128Z,1566251246.128 [HorizontalControl] Loaded
2019-08-19T21:47:26.128Z,1566251246.128 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-19T21:47:26.129Z,1566251246.129 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-19T21:47:26.134Z,1566251246.134 [SpeedControl] Loaded
2019-08-19T21:47:26.134Z,1566251246.134 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-19T21:47:26.135Z,1566251246.135 [LoopControl](DEBUG): Construct LoopControl.
2019-08-19T21:47:26.135Z,1566251246.135 [LoopControl] Loaded
2019-08-19T21:47:26.136Z,1566251246.136 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-19T21:47:26.136Z,1566251246.136 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-19T21:47:26.137Z,1566251246.137 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-19T21:47:26.261Z,1566251246.261 [BuoyancyServo] Loaded
2019-08-19T21:47:26.261Z,1566251246.261 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-19T21:47:26.272Z,1566251246.272 [ElevatorServo] Loaded
2019-08-19T21:47:26.273Z,1566251246.273 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-19T21:47:26.283Z,1566251246.283 [MassServo] Loaded
2019-08-19T21:47:26.283Z,1566251246.283 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-19T21:47:26.294Z,1566251246.294 [RudderServo] Loaded
2019-08-19T21:47:26.294Z,1566251246.294 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-19T21:47:26.305Z,1566251246.305 [ThrusterServo] Loaded
2019-08-19T21:47:26.305Z,1566251246.305 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-19T21:47:26.306Z,1566251246.306 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-19T21:47:26.306Z,1566251246.306 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-19T21:47:26.360Z,1566251246.360 [DepthRateCalculator] Loaded
2019-08-19T21:47:26.360Z,1566251246.360 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-19T21:47:26.365Z,1566251246.365 [PitchRateCalculator] Loaded
2019-08-19T21:47:26.365Z,1566251246.365 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-19T21:47:26.380Z,1566251246.380 [SpeedCalculator] Loaded
2019-08-19T21:47:26.380Z,1566251246.380 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-19T21:47:26.400Z,1566251246.400 [TempGradientCalculator] Loaded
2019-08-19T21:47:26.401Z,1566251246.401 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-19T21:47:26.406Z,1566251246.406 [YawRateCalculator] Loaded
2019-08-19T21:47:26.406Z,1566251246.406 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-19T21:47:26.434Z,1566251246.434 [ElevatorOffsetCalculator] Loaded
2019-08-19T21:47:26.435Z,1566251246.435 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-19T21:47:26.435Z,1566251246.435 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-19T21:47:26.436Z,1566251246.436 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-19T21:47:26.561Z,1566251246.561 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-19T21:47:26.561Z,1566251246.561 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-19T21:47:26.582Z,1566251246.582 [NavChart] Loaded
2019-08-19T21:47:26.582Z,1566251246.582 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-19T21:47:26.586Z,1566251246.586 [UniversalFixResidualReporter] Loaded
2019-08-19T21:47:26.586Z,1566251246.586 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-19T21:47:26.587Z,1566251246.587 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-19T21:47:26.587Z,1566251246.587 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-19T21:47:27.287Z,1566251247.287 [AHRS_M2] Loaded
2019-08-19T21:47:27.287Z,1566251247.287 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-08-19T21:47:27.429Z,1566251247.429 [DataOverHttps] Loaded
2019-08-19T21:47:27.429Z,1566251247.429 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-19T21:47:27.437Z,1566251247.437 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408094E0
2019-08-19T21:47:27.438Z,1566251247.438 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4999
2019-08-19T21:47:27.452Z,1566251247.452 [Depth_Keller] Loaded
2019-08-19T21:47:27.452Z,1566251247.452 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-19T21:47:27.457Z,1566251247.457 [DropWeight] Loaded
2019-08-19T21:47:27.457Z,1566251247.457 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-08-19T21:47:27.588Z,1566251247.588 [DVL_micro] Loaded
2019-08-19T21:47:27.588Z,1566251247.588 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-08-19T21:47:27.682Z,1566251247.682 [NAL9602] Loaded
2019-08-19T21:47:27.682Z,1566251247.682 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-19T21:47:27.698Z,1566251247.698 [Onboard] Loaded
2019-08-19T21:47:27.698Z,1566251247.698 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-19T21:47:27.702Z,1566251247.702 [Radio_Surface] Loaded
2019-08-19T21:47:27.702Z,1566251247.702 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-19T21:47:27.703Z,1566251247.703 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408394E0
2019-08-19T21:47:27.704Z,1566251247.704 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5000
2019-08-19T21:47:29.173Z,1566251249.173 [BPC1] Loaded
2019-08-19T21:47:29.174Z,1566251249.174 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-19T21:47:29.174Z,1566251249.174 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-19T21:47:29.175Z,1566251249.175 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-19T21:47:29.612Z,1566251249.612 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-19T21:47:29.612Z,1566251249.612 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-19T21:47:30.124Z,1566251250.124 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-19T21:47:30.125Z,1566251250.125 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-19T21:47:30.174Z,1566251250.174 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-19T21:47:30.179Z,1566251250.179 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-19T21:47:30.435Z,1566251250.435 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-08-19T21:47:30.440Z,1566251250.440 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-08-19T21:47:30.442Z,1566251250.442 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-08-19T21:47:30.446Z,1566251250.446 [CTD_Seabird](INFO): created writer for : depth
2019-08-19T21:47:30.447Z,1566251250.447 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-08-19T21:47:30.451Z,1566251250.451 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-08-19T21:47:30.452Z,1566251250.452 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-08-19T21:47:30.457Z,1566251250.457 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-08-19T21:47:30.458Z,1566251250.458 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-08-19T21:47:30.462Z,1566251250.462 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-08-19T21:47:30.463Z,1566251250.463 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-08-19T21:47:30.469Z,1566251250.469 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-08-19T21:47:30.469Z,1566251250.469 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-08-19T21:47:30.474Z,1566251250.474 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-08-19T21:47:30.503Z,1566251250.503 [CTD_Seabird] Loaded
2019-08-19T21:47:30.503Z,1566251250.503 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-08-19T21:47:30.544Z,1566251250.544 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409CF4E0
2019-08-19T21:47:30.545Z,1566251250.545 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5001
2019-08-19T21:47:30.560Z,1566251250.560 [PAR_Licor] Loaded
2019-08-19T21:47:30.560Z,1566251250.560 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-08-19T21:47:30.607Z,1566251250.607 [WetLabsBB2FL] Loaded
2019-08-19T21:47:30.608Z,1566251250.608 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-08-19T21:47:30.609Z,1566251250.609 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409FF4E0
2019-08-19T21:47:30.609Z,1566251250.609 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5002
2019-08-19T21:47:30.610Z,1566251250.610 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-19T21:47:30.611Z,1566251250.611 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-19T21:47:30.949Z,1566251250.949 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-19T21:47:30.951Z,1566251250.951 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-19T21:47:31.105Z,1566251251.105 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-19T21:47:31.116Z,1566251251.116 [SBIT] Loaded
2019-08-19T21:47:31.116Z,1566251251.116 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-19T21:47:31.117Z,1566251251.117 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-19T21:47:31.129Z,1566251251.129 [IBIT] Loaded
2019-08-19T21:47:31.129Z,1566251251.129 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-19T21:47:31.132Z,1566251251.132 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-19T21:47:31.266Z,1566251251.266 [CBIT] Loaded
2019-08-19T21:47:31.266Z,1566251251.266 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-19T21:47:31.267Z,1566251251.267 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-19T21:47:31.270Z,1566251251.270 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-19T21:47:31.271Z,1566251251.271 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-19T21:47:31.278Z,1566251251.278 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-19T21:47:31.279Z,1566251251.279 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADE4E0
2019-08-19T21:47:31.279Z,1566251251.279 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5003
2019-08-19T21:47:31.284Z,1566251251.284 [Supervisor](INFO): Main Thread ID is 4916
2019-08-19T21:47:31.284Z,1566251251.284 [Supervisor](DEBUG): Running supervisor.
2019-08-19T21:47:31.285Z,1566251251.285 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5004
2019-08-19T21:47:31.287Z,1566251251.287 [controlThread ThreadHandler](INFO): Handler Thread ID is 5005
2019-08-19T21:47:31.288Z,1566251251.288 [controlThread](DEBUG): Initializing ControlThread
2019-08-19T21:47:31.289Z,1566251251.289 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-19T21:47:31.290Z,1566251251.290 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-19T21:47:31.291Z,1566251251.291 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-19T21:47:31.291Z,1566251251.291 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-19T21:47:31.293Z,1566251251.293 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-19T21:47:31.293Z,1566251251.293 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-19T21:47:31.293Z,1566251251.293 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-19T21:47:31.294Z,1566251251.294 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-19T21:47:31.294Z,1566251251.294 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-19T21:47:31.295Z,1566251251.295 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-19T21:47:31.296Z,1566251251.296 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-19T21:47:31.296Z,1566251251.296 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-19T21:47:31.305Z,1566251251.305 [SBIT](INFO): Initialize SBIT Component.
2019-08-19T21:47:31.306Z,1566251251.306 [SBIT](IMPORTANT): git: 2019-07-01-A
2019-08-19T21:47:31.306Z,1566251251.306 [SBIT](INFO): git hash: 0265b1445bf28f06bbb263eff661be182b07029c
2019-08-19T21:47:31.306Z,1566251251.306 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-19T21:47:31.307Z,1566251251.307 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-08-19T21:47:31.308Z,1566251251.308 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2019-08-19T21:47:31.309Z,1566251251.309 [IBIT](INFO): Initialize IBIT Component.
2019-08-19T21:47:31.310Z,1566251251.310 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-19T21:47:31.311Z,1566251251.311 [logger ThreadHandler](INFO): Handler Thread ID is 5006
2019-08-19T21:47:31.321Z,1566251251.321 [CBIT](DEBUG): Initialized mux pins.
2019-08-19T21:47:31.321Z,1566251251.321 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-19T21:47:31.329Z,1566251251.329 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5007
2019-08-19T21:47:31.330Z,1566251251.330 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-19T21:47:31.341Z,1566251251.341 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5008
2019-08-19T21:47:31.345Z,1566251251.345 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2019-08-19T21:47:31.345Z,1566251251.345 [CBIT](DEBUG): Initializing heartbeat.
2019-08-19T21:47:31.353Z,1566251251.353 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5009
2019-08-19T21:47:31.354Z,1566251251.354 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-08-19T21:47:31.357Z,1566251251.357 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-19T21:47:31.363Z,1566251251.363 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5011
2019-08-19T21:47:31.364Z,1566251251.364 [WetLabsBB2FL](INFO): Powering down
2019-08-19T21:47:31.397Z,1566251251.397 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5012
2019-08-19T21:47:31.406Z,1566251251.406 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-19T21:47:31.407Z,1566251251.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-19T21:47:31.407Z,1566251251.407 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-19T21:47:31.407Z,1566251251.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-19T21:47:31.407Z,1566251251.407 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-19T21:47:31.407Z,1566251251.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-19T21:47:31.408Z,1566251251.408 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-19T21:47:31.408Z,1566251251.408 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-19T21:47:31.408Z,1566251251.408 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-19T21:47:31.408Z,1566251251.408 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-19T21:47:31.408Z,1566251251.408 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-19T21:47:31.409Z,1566251251.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-19T21:47:31.409Z,1566251251.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-19T21:47:31.409Z,1566251251.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-19T21:47:31.409Z,1566251251.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-19T21:47:31.410Z,1566251251.410 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-19T21:47:31.417Z,1566251251.417 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-19T21:47:31.417Z,1566251251.417 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-19T21:47:31.453Z,1566251251.453 [CBIT](DEBUG): Backplane powered.
2019-08-19T21:47:31.454Z,1566251251.454 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-19T21:47:31.484Z,1566251251.484 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-19T21:47:31.508Z,1566251251.508 [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-08-19T21:47:31.533Z,1566251251.533 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-19T21:47:31.603Z,1566251251.603 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-19T21:47:31.604Z,1566251251.604 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-19T21:47:31.621Z,1566251251.621 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-19T21:47:31.644Z,1566251251.644 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-19T21:47:31.647Z,1566251251.647 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-19T21:47:31.676Z,1566251251.676 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-19T21:47:31.679Z,1566251251.679 [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-08-19T21:47:31.689Z,1566251251.689 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,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-08-19T21:47:31.705Z,1566251251.705 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-08-19T21:47:31.745Z,1566251251.745 [Radio_Surface](INFO): Powering up
2019-08-19T21:47:31.851Z,1566251251.851 [DVL_micro](INFO): Initializing
2019-08-19T21:47:31.946Z,1566251251.946 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-19T21:47:31.953Z,1566251251.953 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-19T21:47:31.954Z,1566251251.954 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-19T21:47:31.961Z,1566251251.961 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-19T21:47:31.962Z,1566251251.962 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-19T21:47:31.969Z,1566251251.969 [MassServo](DEBUG): Initializing MassServo.
2019-08-19T21:47:31.970Z,1566251251.970 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-19T21:47:31.977Z,1566251251.977 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-19T21:47:31.978Z,1566251251.978 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-19T21:47:31.985Z,1566251251.985 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-19T21:47:31.987Z,1566251251.987 [CommandLine](FAULT): Scheduling is paused
2019-08-19T21:47:31.988Z,1566251251.988 [CBIT](INFO): Critical error at 20190819T214731
2019-08-19T21:47:31.988Z,1566251251.988 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-08-19T21:47:32.202Z,1566251252.202 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-08-19T21:47:32.202Z,1566251252.202 [DropWeight] Hardware Fault, FailCount= 1
2019-08-19T21:47:32.202Z,1566251252.202 [DropWeight](ERROR): Hardware Fault
2019-08-19T21:47:32.332Z,1566251252.332 [CBIT](INFO): Critical error at 20190819T214732
2019-08-19T21:47:32.335Z,1566251252.335 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-08-19T21:47:32.335Z,1566251252.335 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-08-19T21:47:32.881Z,1566251252.881 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-08-19T21:47:32.881Z,1566251252.881 [RudderServo](FAULT): Rudder failed to initialize
2019-08-19T21:47:32.881Z,1566251252.881 [RudderServo] Communications Fault, FailCount= 1
2019-08-19T21:47:32.881Z,1566251252.881 [RudderServo](ERROR): Communications Fault
2019-08-19T21:47:32.990Z,1566251252.990 [CBIT](INFO): Critical error at 20190819T214732
2019-08-19T21:47:32.992Z,1566251252.992 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-08-19T21:47:33.188Z,1566251253.188 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-19T21:47:33.189Z,1566251253.189 [RudderServo](INFO): Powering down
2019-08-19T21:47:33.912Z,1566251253.912 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-19T21:47:34.054Z,1566251254.054 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-19T21:47:34.058Z,1566251254.058 [CBIT](INFO): Clearing failed state for component RudderServo
2019-08-19T21:47:34.058Z,1566251254.058 [RudderServo] No Fault, FailCount= 1
2019-08-19T21:47:44.142Z,1566251264.142 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004362
2019-08-19T21:47:58.065Z,1566251278.065 [NAL9602](INFO): Powering up NAL9602
2019-08-19T21:48:09.025Z,1566251289.025 [NAL9602](INFO): NAL9602 initialized
2019-08-19T21:48:09.833Z,1566251289.833 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:48:23.533Z,1566251303.533 [NAL9602](INFO): SBD MO Status=2, MOMSN=790, MT Status=2, MTMSN=0
2019-08-19T21:48:23.534Z,1566251303.534 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T21:48:34.917Z,1566251314.917 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-19T21:48:34.930Z,1566251314.930 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-19T21:48:39.859Z,1566251319.859 [DVL_micro](ERROR): only read 42 of 46 data items
2019-08-19T21:48:39.859Z,1566251319.859 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 0.2 0 0.2 2.1 207.8 0 228.5 24.2 0 327 0 0 0 2 0 0 -27.6 517.7 235.3 1 -32.6 -540.6 175.5 1 0 0 0 0 06.40 -1.14 173.2 0.2 18 35.0 1489 119
2019-08-19T21:48:46.423Z,1566251326.423 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.018323
CHAN A1 (24V): 0.000615
CHAN A2 (12V): 0.019983
CHAN A3 (5V): 0.005214
CHAN B0 (3.3V): 0.004531
CHAN B1 (3.15aV): 0.004718
CHAN B2 (3.15bV): 0.003950
CHAN B3 (GND): -0.001081
OPEN: 0.009835
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-19T21:48:47.937Z,1566251327.937 [NAL9602](INFO): SBD MO Status=2, MOMSN=790, MT Status=2, MTMSN=0
2019-08-19T21:48:47.937Z,1566251327.937 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T21:48:58.254Z,1566251338.254 [NAL9602](INFO): SBD MO Status=0, MOMSN=790, MT Status=0, MTMSN=0
2019-08-19T21:48:58.254Z,1566251338.254 [NAL9602](INFO): No messages in MT queue
2019-08-19T21:48:59.069Z,1566251339.069 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:01.913Z,1566251341.913 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:05.141Z,1566251345.141 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:07.172Z,1566251347.172 [CommandLine](IMPORTANT): got command help
2019-08-19T21:49:07.961Z,1566251347.961 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:10.801Z,1566251350.801 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:14.037Z,1566251354.037 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:16.849Z,1566251356.849 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:19.837Z,1566251359.837 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:23.077Z,1566251363.077 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:25.894Z,1566251365.894 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:28.331Z,1566251368.331 [SBIT](IMPORTANT): SBIT PASSED
2019-08-19T21:49:28.397Z,1566251368.397 [CommandLine](IMPORTANT): got command configSet list
2019-08-19T21:49:28.397Z,1566251368.397 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-19T21:49:28.398Z,1566251368.398 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-08-19T21:49:28.398Z,1566251368.398 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-08-19T21:49:28.399Z,1566251368.399 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-19T21:49:28.399Z,1566251368.399 [CommandLine](IMPORTANT): PAR_Licor.darkCount=-15 count;

2019-08-19T21:49:28.399Z,1566251368.399 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-08-19T21:49:28.399Z,1566251368.399 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=250 cubic_centimeter;

2019-08-19T21:49:28.399Z,1566251368.399 [CommandLine](IMPORTANT): VerticalControl.massDefault=-11 millimeter;

2019-08-19T21:49:28.735Z,1566251368.735 [MissionManager](IMPORTANT): Started mission Startup
2019-08-19T21:49:28.735Z,1566251368.735 [Startup] Running Loop=1
2019-08-19T21:49:28.736Z,1566251368.736 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-19T21:49:28.736Z,1566251368.736 [Startup:A.GoToSurface] Running Loop=1
2019-08-19T21:49:28.736Z,1566251368.736 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-19T21:49:28.736Z,1566251368.736 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-19T21:49:28.737Z,1566251368.737 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-19T21:49:28.737Z,1566251368.737 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-19T21:49:28.738Z,1566251368.738 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-19T21:49:28.738Z,1566251368.738 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-19T21:49:28.739Z,1566251368.739 [Startup:StartupSatComms] Running Loop=1
2019-08-19T21:49:28.740Z,1566251368.740 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-19T21:49:28.740Z,1566251368.740 [Startup:StartupSatComms:A] Running Loop=1
2019-08-19T21:49:29.109Z,1566251369.109 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:29.139Z,1566251369.139 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-19T21:49:31.973Z,1566251371.973 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:35.189Z,1566251375.189 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:38.001Z,1566251378.001 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:40.845Z,1566251380.845 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:44.077Z,1566251384.077 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:46.889Z,1566251386.889 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:50.121Z,1566251390.121 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:52.981Z,1566251392.981 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:49:53.340Z,1566251393.340 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214557.00,A,3648.15670,N,12147.27593,W,0.175,340.03,190819,,,A*74
2019-08-19T21:49:53.358Z,1566251393.358 [NAL9602](INFO): GPS fix at 20190819T214557: (36.802612, -121.787932)
2019-08-19T21:49:53.430Z,1566251393.430 [Startup:StartupSatComms:A] Stopped
2019-08-19T21:49:53.430Z,1566251393.430 [Startup:StartupSatComms:B] Running Loop=1
2019-08-19T21:49:53.874Z,1566251393.874 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-19T21:50:03.266Z,1566251403.266 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20190805T133200/Courier0172.lzma
2019-08-19T21:50:04.075Z,1566251404.075 [DataOverHttps](INFO): Moved sent file to Logs/20190805T133200/Courier0172.lzma.bak
2019-08-19T21:50:04.075Z,1566251404.075 [DataOverHttps](INFO): SBD MOMSN=11593079
2019-08-19T21:50:06.305Z,1566251406.305 [DVL_micro](ERROR): checksum mismatch: reported106 , calculated:121
2019-08-19T21:50:06.306Z,1566251406.306 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 0.2 0 0.2 9.5 -333.4 0 278.0 4.2 0 64 0 -123 0 2 0 1 -816.0 -85.1 -29.8 582.2 -35.4 1 0 249 0 0 0 0 0 0 -6.47 -1.07 219.0 0.2 18.5 0.005 35.0 1489 106
2019-08-19T21:50:26.058Z,1566251426.058 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T21:50:31.437Z,1566251431.437 [DataOverHttps](INFO): Sending 428 bytes from file Logs/20190819T214719/Courier0000.lzma
2019-08-19T21:50:32.242Z,1566251432.242 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0000.lzma.bak
2019-08-19T21:50:32.243Z,1566251432.243 [DataOverHttps](INFO): SBD MOMSN=11593084
2019-08-19T21:50:48.750Z,1566251448.750 [DataOverHttps](INFO): Sending 424 bytes from file Logs/20190805T133200/Express0173.lzma
2019-08-19T21:50:49.555Z,1566251449.555 [DataOverHttps](INFO): Moved sent file to Logs/20190805T133200/Express0173.lzma.bak
2019-08-19T21:50:49.555Z,1566251449.555 [DataOverHttps](INFO): SBD MOMSN=11593092
2019-08-19T21:50:53.609Z,1566251453.609 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-19T21:49:53.4Z
2019-08-19T21:50:53.610Z,1566251453.610 [Startup:StartupSatComms:B] Stopped
2019-08-19T21:50:53.610Z,1566251453.610 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-19T21:50:53.610Z,1566251453.610 [Startup:StartupSatComms] Stopped
2019-08-19T21:50:53.610Z,1566251453.610 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-19T21:50:53.621Z,1566251453.621 [Startup](INFO): Completed Startup
2019-08-19T21:50:53.621Z,1566251453.621 [MissionManager](INFO): Startup is completed.
2019-08-19T21:50:53.622Z,1566251453.622 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-19T21:50:53.622Z,1566251453.622 [Startup] Stopped
2019-08-19T21:50:53.622Z,1566251453.622 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-19T21:50:53.622Z,1566251453.622 [Startup:A.GoToSurface] Stopped
2019-08-19T21:50:53.622Z,1566251453.622 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-19T21:50:54.030Z,1566251454.030 [MissionManager](IMPORTANT): Started mission Default
2019-08-19T21:50:54.030Z,1566251454.030 [Default] Running Loop=1
2019-08-19T21:50:54.030Z,1566251454.030 [Default](DEBUG): Aggregate::initialize Default
2019-08-19T21:50:54.030Z,1566251454.030 [Default:B.GoToSurface] Running Loop=1
2019-08-19T21:50:54.030Z,1566251454.030 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-19T21:50:54.031Z,1566251454.031 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-19T21:50:54.031Z,1566251454.031 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-19T21:50:54.031Z,1566251454.031 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-19T21:50:54.032Z,1566251454.032 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-19T21:50:54.032Z,1566251454.032 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-19T21:50:54.032Z,1566251454.032 [Default:A.Wait] Running Loop=1
2019-08-19T21:50:54.032Z,1566251454.032 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-19T21:51:07.303Z,1566251467.303 [Default:A.Wait](INFO): Done Waiting.
2019-08-19T21:51:07.303Z,1566251467.303 [Default:A.Wait] Stopped
2019-08-19T21:51:07.303Z,1566251467.303 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T21:51:07.737Z,1566251467.737 [Default:CheckIn] Running Loop=1
2019-08-19T21:51:07.737Z,1566251467.737 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T21:51:07.738Z,1566251467.738 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T21:51:08.421Z,1566251468.421 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-19T21:51:09.713Z,1566251469.713 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:51:09.921Z,1566251469.921 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214714.00,A,3648.16666,N,12147.28029,W,0.408,226.12,190819,,,A*70
2019-08-19T21:51:09.923Z,1566251469.923 [NAL9602](INFO): GPS fix at 20190819T214714: (36.802778, -121.788005)
2019-08-19T21:51:09.957Z,1566251469.957 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T21:51:09.957Z,1566251469.957 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T21:51:10.348Z,1566251470.348 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-19T21:51:15.759Z,1566251475.759 [DataOverHttps](INFO): Sending 908 bytes from file Logs/20190819T214719/Express0001.lzma
2019-08-19T21:51:16.562Z,1566251476.562 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0001.lzma.bak
2019-08-19T21:51:16.562Z,1566251476.562 [DataOverHttps](INFO): SBD MOMSN=11593124
2019-08-19T21:51:30.996Z,1566251490.996 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190819T214719/Courier0004.lzma
2019-08-19T21:51:31.803Z,1566251491.803 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0004.lzma.bak
2019-08-19T21:51:31.803Z,1566251491.803 [DataOverHttps](INFO): SBD MOMSN=11593147
2019-08-19T21:51:45.118Z,1566251505.118 [NAL9602](INFO): SBD MO Status=2, MOMSN=791, MT Status=2, MTMSN=0
2019-08-19T21:51:45.119Z,1566251505.119 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T21:51:49.336Z,1566251509.336 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20190819T214719/Express0005.lzma
2019-08-19T21:51:50.142Z,1566251510.142 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0005.lzma.bak
2019-08-19T21:51:50.143Z,1566251510.143 [DataOverHttps](INFO): SBD MOMSN=11593152
2019-08-19T21:51:54.841Z,1566251514.841 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T21:51:54.842Z,1566251514.842 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T21:51:54.842Z,1566251514.842 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T21:52:21.861Z,1566251541.861 [NAL9602](INFO): SBD MO Status=2, MOMSN=791, MT Status=2, MTMSN=0
2019-08-19T21:52:21.862Z,1566251541.862 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T21:52:33.627Z,1566251553.627 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:52:46.553Z,1566251566.553 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:52:59.476Z,1566251579.476 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:53:12.398Z,1566251592.398 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:53:16.229Z,1566251596.229 [CommandLine](INFO): End of History
2019-08-19T21:53:16.234Z,1566251596.234 [CommandLine](INFO): End of History
2019-08-19T21:53:16.237Z,1566251596.237 [CommandLine](INFO): End of History
2019-08-19T21:53:25.335Z,1566251605.335 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:53:33.374Z,1566251613.374 [DVL_micro](ERROR): checksum mismatch: reported102 , calculated:118
2019-08-19T21:53:33.374Z,1566251613.374 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 0.2 0 0.2 9.5 -238.9 0 220.8 -161.8 0 -26 0 -264 0 2 0 1 -613.5 407.7 -9.8 1 72.2 -63.7 1 0 317 0 0 0 0 0 0 -6.11 -0.99 205.3 0.2 18.5 0.005 35.0 1489 102
2019-08-19T21:53:38.247Z,1566251618.247 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:53:51.193Z,1566251631.193 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:54:04.129Z,1566251644.129 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:54:17.050Z,1566251657.050 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:54:29.178Z,1566251669.178 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:54:42.474Z,1566251682.474 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:54:55.021Z,1566251695.021 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T21:55:02.302Z,1566251702.302 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:55:05.492Z,1566251705.492 [DVL_micro](ERROR): only read 2 of 46 data items
2019-08-19T21:55:05.492Z,1566251705.492 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1.2 0 0.2 9.5 -245.4 0 257.3 39.2 0 114 0 -812 0 2 0 1 -670.9 -88.8 6.4 1 658.4 156.7 4.4 1 0 1235 0 0 0 0 0 0 -6.21 -0.99 185.9 0.2 18.6 0.005 35.0 1489 92
2019-08-19T21:55:13.604Z,1566251713.604 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:55:24.935Z,1566251724.935 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:55:24.939Z,1566251724.939 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2019-08-19T21:55:36.229Z,1566251736.229 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:55:47.548Z,1566251747.548 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:55:58.852Z,1566251758.852 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:56:10.177Z,1566251770.177 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:56:20.229Z,1566251780.229 [NAL9602](INFO): SBD MO Status=2, MOMSN=791, MT Status=2, MTMSN=0
2019-08-19T21:56:20.229Z,1566251780.229 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T21:56:20.654Z,1566251780.654 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-19T21:56:21.859Z,1566251781.859 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:56:33.168Z,1566251793.168 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:56:44.918Z,1566251804.918 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:56:51.372Z,1566251811.372 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T21:56:55.465Z,1566251815.465 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T21:56:55.465Z,1566251815.465 [Default:CheckIn:C.Wait] Stopped
2019-08-19T21:56:55.466Z,1566251815.466 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T21:56:55.466Z,1566251815.466 [Default:CheckIn:D] Running Loop=1
2019-08-19T21:56:55.813Z,1566251815.813 [Default:CheckIn:D] Stopped
2019-08-19T21:56:55.813Z,1566251815.813 [Default:CheckIn:E] Running Loop=1
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.029719 min 
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn:E] Stopped
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn] Stopped
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn](INFO): Running loop #2
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn] Running Loop=2
2019-08-19T21:56:56.227Z,1566251816.227 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T21:56:56.228Z,1566251816.228 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T21:56:57.023Z,1566251817.023 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:56:57.837Z,1566251817.837 [NAL9602](DEBUG): Fix Requested
2019-08-19T21:56:58.205Z,1566251818.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215303.00,A,3648.16462,N,12147.27923,W,0.039,331.48,190819,,,A*77
2019-08-19T21:56:58.208Z,1566251818.208 [NAL9602](INFO): GPS fix at 20190819T215303: (36.802744, -121.787987)
2019-08-19T21:56:58.264Z,1566251818.264 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T21:56:58.264Z,1566251818.264 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T21:57:04.400Z,1566251824.400 [DVL_micro](ERROR): only read 2 of 46 data items
2019-08-19T21:57:04.405Z,1566251824.405 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0.2 0 0.2 9.6 -312.6 0 244.4 -23.3 0 135 0 124 0 2 0 1 -743.4 -28.8 -36.8 1 723.1 -172.8 -45.9 1 0 14 0 0 0 0 0 0 -6.17 -0.96 164.0 0.2 18.6 0.005 35.0 1489 127
2019-08-19T21:57:06.768Z,1566251826.768 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190819T214719/Courier0007.lzma
2019-08-19T21:57:07.574Z,1566251827.574 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0007.lzma.bak
2019-08-19T21:57:07.575Z,1566251827.575 [DataOverHttps](IMPORTANT): SBD MOMSN=11593165, MTMSN=20190819T215312
2019-08-19T21:57:08.044Z,1566251828.044 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:57:15.719Z,1566251835.719 [DVL_micro](ERROR): checksum mismatch: reported104 , calculated:118
2019-08-19T21:57:15.719Z,1566251835.719 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 0.2 0 0.2 4.1 -205.3 0 277.0 -130.7 0 -364 0 0 0 2 0 0 -643.7 444.6 38.7 1 471.4 -6.9 1 0 0 0 0 0 0 0 0 -6.15 -0.96 161.7 0.2 18.6 0.005 35.0 1489 104
2019-08-19T21:57:19.359Z,1566251839.359 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T21:57:19.481Z,1566251839.481 [DataOverHttps](INFO): Received command:failc list
2019-08-19T21:57:19.529Z,1566251839.529 [CommandLine](IMPORTANT): got command failComponent 
2019-08-19T21:57:19.529Z,1566251839.529 [CommandLine](FAULT): Incomplete syntax. Try: help failComponent
2019-08-19T21:57:25.756Z,1566251845.756 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20190819T214719/Express0008.lzma
2019-08-19T21:57:26.562Z,1566251846.562 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0008.lzma.bak
2019-08-19T21:57:26.563Z,1566251846.563 [DataOverHttps](INFO): SBD MOMSN=11593169
2019-08-19T21:57:41.096Z,1566251861.096 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T214719/Courier0010.lzma
2019-08-19T21:57:41.902Z,1566251861.902 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0010.lzma.bak
2019-08-19T21:57:41.902Z,1566251861.902 [DataOverHttps](INFO): SBD MOMSN=11593173
2019-08-19T21:57:58.597Z,1566251878.597 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20190819T214719/Express0011.lzma
2019-08-19T21:57:59.402Z,1566251879.402 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0011.lzma.bak
2019-08-19T21:57:59.402Z,1566251879.402 [DataOverHttps](INFO): SBD MOMSN=11593175
2019-08-19T21:58:05.262Z,1566251885.262 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T21:58:05.262Z,1566251885.262 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T21:58:05.262Z,1566251885.262 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T21:59:26.702Z,1566251966.702 [NAL9602](INFO): SBD MO Status=2, MOMSN=791, MT Status=2, MTMSN=0
2019-08-19T21:59:26.703Z,1566251966.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T21:59:44.054Z,1566251984.054 [NAL9602](INFO): SBD MO Status=2, MOMSN=791, MT Status=2, MTMSN=0
2019-08-19T21:59:44.054Z,1566251984.054 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T22:00:01.441Z,1566252001.441 [NAL9602](INFO): SBD MO Status=2, MOMSN=791, MT Status=2, MTMSN=0
2019-08-19T22:00:01.442Z,1566252001.442 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T22:00:26.107Z,1566252026.107 [NAL9602](INFO): SBD MO Status=0, MOMSN=791, MT Status=0, MTMSN=0
2019-08-19T22:00:26.107Z,1566252026.107 [NAL9602](INFO): No messages in MT queue
2019-08-19T22:00:31.938Z,1566252031.938 [CommandLine](IMPORTANT): got command maintain control platform_buoyancy_position 200.000000 cubic_centimeter
2019-08-19T22:00:31.939Z,1566252031.939 [ComponentRegistry](DEBUG): SyncComponent "Maintain_platform_buoyancy_position" handled in the control thread.
2019-08-19T22:00:32.214Z,1566252032.214 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_platform_buoyancy_position,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-08-19T22:00:56.804Z,1566252056.804 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T22:02:16.418Z,1566252136.418 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:02:32.184Z,1566252152.184 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:02:32.273Z,1566252152.273 [CBIT](INFO): Clearing failed state for component DropWeight
2019-08-19T22:02:32.273Z,1566252152.273 [DropWeight] No Fault, FailCount= 1
2019-08-19T22:02:47.534Z,1566252167.534 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:03:02.463Z,1566252182.463 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:03:05.710Z,1566252185.710 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:03:05.710Z,1566252185.710 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:03:05.710Z,1566252185.710 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:03:05.710Z,1566252185.710 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:03:06.142Z,1566252186.142 [Default:CheckIn:D] Stopped
2019-08-19T22:03:06.142Z,1566252186.142 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:03:06.528Z,1566252186.528 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.201870 min 
2019-08-19T22:03:06.528Z,1566252186.528 [Default:CheckIn:E] Stopped
2019-08-19T22:03:06.528Z,1566252186.528 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:03:06.528Z,1566252186.528 [Default:CheckIn] Stopped
2019-08-19T22:03:06.528Z,1566252186.528 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:03:06.529Z,1566252186.529 [Default:CheckIn](INFO): Running loop #3
2019-08-19T22:03:06.529Z,1566252186.529 [Default:CheckIn] Running Loop=3
2019-08-19T22:03:06.529Z,1566252186.529 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:03:06.529Z,1566252186.529 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:03:08.117Z,1566252188.117 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:03:08.535Z,1566252188.535 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215913.00,A,3648.16893,N,12147.28392,W,0.408,331.48,190819,,,A*77
2019-08-19T22:03:08.542Z,1566252188.542 [NAL9602](INFO): GPS fix at 20190819T215913: (36.802816, -121.788065)
2019-08-19T22:03:08.786Z,1566252188.786 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:03:08.786Z,1566252188.786 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:03:11.152Z,1566252191.152 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position
2019-08-19T22:03:11.311Z,1566252191.311 [Reporter](INFO): platform_buoyancy_position 200.000000 cc
2019-08-19T22:03:14.256Z,1566252194.256 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190819T214719/Courier0013.lzma
2019-08-19T22:03:14.418Z,1566252194.418 [DVL_micro](ERROR): checksum mismatch: reported84 , calculated:73
2019-08-19T22:03:14.418Z,1566252194.418 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 0.2 0 0.2 4.5 -271.4 0 179.5 329.8 0 19 0 0 0 2 0 0 -601.8 -10.6 1 1108.4 373.8 48.3 1 0 0 0 0 0 0 0 0 -6.15 -0.94 139.6 0.2 18.6 0.005 35.0 1489 84
2019-08-19T22:03:15.066Z,1566252195.066 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0013.lzma.bak
2019-08-19T22:03:15.066Z,1566252195.066 [DataOverHttps](INFO): SBD MOMSN=11593187
2019-08-19T22:03:17.714Z,1566252197.714 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:03:31.332Z,1566252211.332 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20190819T214719/Express0014.lzma
2019-08-19T22:03:32.138Z,1566252212.138 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0014.lzma.bak
2019-08-19T22:03:32.139Z,1566252212.139 [DataOverHttps](INFO): SBD MOMSN=11593190
2019-08-19T22:03:32.614Z,1566252212.614 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:03:39.088Z,1566252219.088 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:03:39.088Z,1566252219.088 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:03:39.088Z,1566252219.088 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:03:47.971Z,1566252227.971 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:04:02.949Z,1566252242.949 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:04:17.871Z,1566252257.871 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:04:32.851Z,1566252272.851 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:04:49.006Z,1566252289.006 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:05:00.312Z,1566252300.312 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:05:12.001Z,1566252312.001 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:05:23.315Z,1566252323.315 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:05:34.627Z,1566252334.627 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:05:46.392Z,1566252346.392 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:05:57.676Z,1566252357.676 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:06:09.050Z,1566252369.050 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:06:20.311Z,1566252380.311 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:06:31.626Z,1566252391.626 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:06:35.651Z,1566252395.651 [NAL9602](INFO): SBD MO Status=2, MOMSN=792, MT Status=2, MTMSN=0
2019-08-19T22:06:35.651Z,1566252395.651 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T22:06:43.382Z,1566252403.382 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:06:54.644Z,1566252414.644 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:07:05.947Z,1566252425.947 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:07:54.835Z,1566252474.835 [NAL9602](INFO): SBD MO Status=2, MOMSN=792, MT Status=2, MTMSN=0
2019-08-19T22:07:54.835Z,1566252474.835 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-19T22:08:10.997Z,1566252490.997 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-19T22:08:39.753Z,1566252519.753 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:08:39.753Z,1566252519.753 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:08:39.754Z,1566252519.754 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:08:39.754Z,1566252519.754 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:08:40.161Z,1566252520.161 [Default:CheckIn:D] Stopped
2019-08-19T22:08:40.161Z,1566252520.161 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:08:40.525Z,1566252520.525 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.768850 min 
2019-08-19T22:08:40.525Z,1566252520.525 [Default:CheckIn:E] Stopped
2019-08-19T22:08:40.525Z,1566252520.525 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:08:40.525Z,1566252520.525 [Default:CheckIn] Stopped
2019-08-19T22:08:40.525Z,1566252520.525 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:08:40.525Z,1566252520.525 [Default:CheckIn](INFO): Running loop #4
2019-08-19T22:08:40.525Z,1566252520.525 [Default:CheckIn] Running Loop=4
2019-08-19T22:08:40.526Z,1566252520.526 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:08:40.526Z,1566252520.526 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:08:42.101Z,1566252522.101 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:08:42.518Z,1566252522.518 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220447.00,A,3648.16679,N,12147.28047,W,1.127,67.75,190819,,,A*4B
2019-08-19T22:08:42.520Z,1566252522.520 [NAL9602](INFO): GPS fix at 20190819T220447: (36.802780, -121.788008)
2019-08-19T22:08:42.544Z,1566252522.544 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:08:42.544Z,1566252522.544 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:08:51.000Z,1566252531.000 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190819T214719/Courier0016.lzma
2019-08-19T22:08:51.806Z,1566252531.806 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0016.lzma.bak
2019-08-19T22:08:51.807Z,1566252531.807 [DataOverHttps](INFO): SBD MOMSN=11593198
2019-08-19T22:09:08.601Z,1566252548.601 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20190819T214719/Express0017.lzma
2019-08-19T22:09:09.406Z,1566252549.406 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0017.lzma.bak
2019-08-19T22:09:09.406Z,1566252549.406 [DataOverHttps](INFO): SBD MOMSN=11593201
2019-08-19T22:09:14.226Z,1566252554.226 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:09:14.226Z,1566252554.226 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:09:14.226Z,1566252554.226 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:09:14.852Z,1566252554.852 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T22:09:40.338Z,1566252580.338 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:40.760Z,1566252580.760 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:41.158Z,1566252581.158 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:41.660Z,1566252581.660 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:41.991Z,1566252581.991 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:42.470Z,1566252582.470 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:42.858Z,1566252582.858 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:43.264Z,1566252583.264 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:43.660Z,1566252583.660 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:44.098Z,1566252584.098 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:44.457Z,1566252584.457 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:44.872Z,1566252584.872 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:45.266Z,1566252585.266 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:45.682Z,1566252585.682 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:46.077Z,1566252586.077 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:46.500Z,1566252586.500 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:46.950Z,1566252586.950 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:47.330Z,1566252587.330 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:47.715Z,1566252587.715 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:48.138Z,1566252588.138 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:48.498Z,1566252588.498 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:48.918Z,1566252588.918 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:49.306Z,1566252589.306 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:49.723Z,1566252589.723 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:50.122Z,1566252590.122 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:50.572Z,1566252590.572 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:50.946Z,1566252590.946 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:51.335Z,1566252591.335 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:51.730Z,1566252591.730 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:52.150Z,1566252592.150 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:52.538Z,1566252592.538 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:52.960Z,1566252592.960 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:09:53.352Z,1566252593.352 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:11:57.379Z,1566252717.379 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:12:04.308Z,1566252724.308 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:12:19.659Z,1566252739.659 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:12:34.982Z,1566252754.982 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:12:49.901Z,1566252769.901 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:13:04.878Z,1566252784.878 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:13:20.236Z,1566252800.236 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:13:35.620Z,1566252815.620 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:13:50.927Z,1566252830.927 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:13:56.174Z,1566252836.174 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:13:56.623Z,1566252836.623 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:13:56.993Z,1566252836.993 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:13:57.787Z,1566252837.787 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -32.00 mm (1 active estimators).
2019-08-19T22:14:00.794Z,1566252840.794 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:14:01.139Z,1566252841.139 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:14:01.653Z,1566252841.653 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:14:01.940Z,1566252841.940 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:14:02.398Z,1566252842.398 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:14:02.762Z,1566252842.762 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:14:03.984Z,1566252843.984 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:14:06.387Z,1566252846.387 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:14:14.521Z,1566252854.521 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:14:14.521Z,1566252854.521 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:14:14.521Z,1566252854.521 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:14:14.522Z,1566252854.522 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:14:15.017Z,1566252855.017 [Default:CheckIn:D] Stopped
2019-08-19T22:14:15.017Z,1566252855.017 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:14:15.361Z,1566252855.361 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.349780 min 
2019-08-19T22:14:15.361Z,1566252855.361 [Default:CheckIn:E] Stopped
2019-08-19T22:14:15.361Z,1566252855.361 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:14:15.361Z,1566252855.361 [Default:CheckIn] Stopped
2019-08-19T22:14:15.362Z,1566252855.362 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:14:15.362Z,1566252855.362 [Default:CheckIn](INFO): Running loop #5
2019-08-19T22:14:15.362Z,1566252855.362 [Default:CheckIn] Running Loop=5
2019-08-19T22:14:15.362Z,1566252855.362 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:14:15.362Z,1566252855.362 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:14:16.902Z,1566252856.902 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:14:17.262Z,1566252857.262 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221022.00,A,3648.17431,N,12147.28731,W,0.525,0.00,190819,,,A*70
2019-08-19T22:14:17.264Z,1566252857.264 [NAL9602](INFO): GPS fix at 20190819T221022: (36.802905, -121.788122)
2019-08-19T22:14:17.331Z,1566252857.331 [UniversalFixResidualReporter](INFO): Fix residual: 42.9 %DT, over the last 519.5 m. Residual distance 222.9 m at bearing -62.3 degrees. Fix at (36.8029, -121.7881) with 17.2 m made good.
2019-08-19T22:14:17.332Z,1566252857.332 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:14:17.332Z,1566252857.332 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:14:20.672Z,1566252860.672 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20190819T214719/Courier0019.lzma
2019-08-19T22:14:21.482Z,1566252861.482 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0019.lzma.bak
2019-08-19T22:14:21.483Z,1566252861.483 [DataOverHttps](INFO): SBD MOMSN=11593212
2019-08-19T22:14:21.541Z,1566252861.541 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-08-19T22:14:39.580Z,1566252879.580 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190819T214719/Express0020.lzma
2019-08-19T22:14:40.388Z,1566252880.388 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0020.lzma.bak
2019-08-19T22:14:40.388Z,1566252880.388 [DataOverHttps](INFO): SBD MOMSN=11593216
2019-08-19T22:14:44.168Z,1566252884.168 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:14:45.477Z,1566252885.477 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:14:45.477Z,1566252885.477 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:14:45.478Z,1566252885.478 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:14:47.834Z,1566252887.834 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-19T22:14:47.917Z,1566252887.917 [NAL9602](FAULT): received: 
+CSQ:0

OK2, 2, 0, 0, 0

OK
2019-08-19T22:14:47.917Z,1566252887.917 [NAL9602] Data Fault, FailCount= 1
2019-08-19T22:14:47.917Z,1566252887.917 [NAL9602](ERROR): Data Fault
2019-08-19T22:14:48.001Z,1566252888.001 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-19T22:14:48.186Z,1566252888.186 [NAL9602](INFO): Powering down
2019-08-19T22:14:48.609Z,1566252888.609 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2019-08-19T22:14:48.609Z,1566252888.609 [NAL9602] Hardware Fault, FailCount= 1
2019-08-19T22:14:48.609Z,1566252888.609 [NAL9602](ERROR): Hardware Fault
2019-08-19T22:14:49.112Z,1566252889.112 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-19T22:14:49.112Z,1566252889.112 [NAL9602] No Fault, FailCount= 1
2019-08-19T22:14:57.090Z,1566252897.090 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:15:09.875Z,1566252909.875 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:15:18.545Z,1566252918.545 [NAL9602](INFO): Powering up NAL9602
2019-08-19T22:15:22.593Z,1566252922.593 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:15:29.436Z,1566252929.436 [NAL9602](INFO): NAL9602 initialized
2019-08-19T22:15:35.527Z,1566252935.527 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:15:42.814Z,1566252942.814 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:43.202Z,1566252943.202 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:43.636Z,1566252943.636 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:44.018Z,1566252944.018 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:44.469Z,1566252944.469 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:44.908Z,1566252944.908 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:45.330Z,1566252945.330 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:45.725Z,1566252945.725 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:46.144Z,1566252946.144 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:46.537Z,1566252946.537 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:46.994Z,1566252946.994 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:47.358Z,1566252947.358 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:47.831Z,1566252947.831 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:48.131Z,1566252948.131 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:15:48.150Z,1566252948.150 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:48.601Z,1566252948.601 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:48.954Z,1566252948.954 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:49.391Z,1566252949.391 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:49.766Z,1566252949.766 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:50.214Z,1566252950.214 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:50.573Z,1566252950.573 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:50.992Z,1566252950.992 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:51.378Z,1566252951.378 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:51.793Z,1566252951.793 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:52.180Z,1566252952.180 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:52.621Z,1566252952.621 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:53.050Z,1566252953.050 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:53.454Z,1566252953.454 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:53.827Z,1566252953.827 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:54.283Z,1566252954.283 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:54.610Z,1566252954.610 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:55.031Z,1566252955.031 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:55.418Z,1566252955.418 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:55.870Z,1566252955.870 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:56.234Z,1566252956.234 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:56.678Z,1566252956.678 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:57.034Z,1566252957.034 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:57.474Z,1566252957.474 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:57.836Z,1566252957.836 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:58.264Z,1566252958.264 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:58.650Z,1566252958.650 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:59.065Z,1566252959.065 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:59.461Z,1566252959.461 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:15:59.914Z,1566252959.914 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:00.252Z,1566252960.252 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T22:16:00.318Z,1566252960.318 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:00.771Z,1566252960.771 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:01.078Z,1566252961.078 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:16:01.174Z,1566252961.174 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:01.514Z,1566252961.514 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:01.917Z,1566252961.917 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:02.320Z,1566252962.320 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:02.700Z,1566252962.700 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:03.162Z,1566252963.162 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:03.206Z,1566252963.206 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.196793
2019-08-19T22:16:03.499Z,1566252963.499 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:03.922Z,1566252963.922 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:04.310Z,1566252964.310 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:06.405Z,1566252966.405 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:06.722Z,1566252966.722 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:07.143Z,1566252967.143 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:07.538Z,1566252967.538 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:07.955Z,1566252967.955 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:08.354Z,1566252968.354 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:08.772Z,1566252968.772 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:09.162Z,1566252969.162 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:09.637Z,1566252969.637 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:09.960Z,1566252969.960 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:10.376Z,1566252970.376 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:10.770Z,1566252970.770 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:11.184Z,1566252971.184 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:11.578Z,1566252971.578 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:12.012Z,1566252972.012 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:12.392Z,1566252972.392 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:12.858Z,1566252972.858 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:16:13.597Z,1566252973.597 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:16:26.579Z,1566252986.579 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:16:34.197Z,1566252994.197 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003148
2019-08-19T22:16:39.495Z,1566252999.495 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:16:52.428Z,1566253012.428 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-08-19T22:17:46.805Z,1566253066.805 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:17:47.613Z,1566253067.613 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.195641
2019-08-19T22:18:21.953Z,1566253101.953 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:18:32.243Z,1566253112.243 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 5.
2019-08-19T22:18:32.248Z,1566253112.248 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2019-08-19T22:18:41.502Z,1566253121.502 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003195
2019-08-19T22:19:15.461Z,1566253155.461 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:15.897Z,1566253155.897 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:16.257Z,1566253156.257 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:16.673Z,1566253156.673 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:17.066Z,1566253157.066 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:17.487Z,1566253157.487 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:17.956Z,1566253157.956 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:18.400Z,1566253158.400 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:18.747Z,1566253158.747 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:19.171Z,1566253159.171 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:19.563Z,1566253159.563 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:20.042Z,1566253160.042 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:20.370Z,1566253160.370 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:20.821Z,1566253160.821 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:21.182Z,1566253161.182 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:21.639Z,1566253161.639 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:21.974Z,1566253161.974 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:22.396Z,1566253162.396 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:22.781Z,1566253162.781 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:23.204Z,1566253163.204 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:23.599Z,1566253163.599 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:24.020Z,1566253164.020 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:24.411Z,1566253164.411 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:24.796Z,1566253164.796 [DVL_micro](ERROR): only read 43 of 46 data items
2019-08-19T22:19:24.800Z,1566253164.800 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0 0.1 1.0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2.46 -12.91 197.2 0.2 18.5 0.005 35.0 1489 96
2019-08-19T22:19:24.830Z,1566253164.830 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:25.206Z,1566253165.206 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:25.659Z,1566253165.659 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:26.023Z,1566253166.023 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:26.441Z,1566253166.441 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:26.831Z,1566253166.831 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:27.255Z,1566253167.255 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:27.643Z,1566253167.643 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:28.082Z,1566253168.082 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:28.438Z,1566253168.438 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:28.862Z,1566253168.862 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:29.270Z,1566253169.270 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:29.671Z,1566253169.671 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:30.069Z,1566253170.069 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:30.498Z,1566253170.498 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:30.886Z,1566253170.886 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:31.423Z,1566253171.423 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:31.692Z,1566253171.692 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:32.097Z,1566253172.097 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:32.401Z,1566253172.401 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:19:32.498Z,1566253172.498 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:32.910Z,1566253172.910 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:33.300Z,1566253173.300 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:33.719Z,1566253173.719 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:34.112Z,1566253174.112 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:34.550Z,1566253174.550 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:34.953Z,1566253174.953 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:35.322Z,1566253175.322 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:35.723Z,1566253175.723 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:36.141Z,1566253176.141 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:36.573Z,1566253176.573 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:36.970Z,1566253176.970 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:37.326Z,1566253177.326 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:37.782Z,1566253177.782 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:38.135Z,1566253178.135 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:38.558Z,1566253178.558 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:38.951Z,1566253178.951 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:39.371Z,1566253179.371 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:39.760Z,1566253179.760 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:40.194Z,1566253180.194 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:40.558Z,1566253180.558 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:40.979Z,1566253180.979 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:41.375Z,1566253181.375 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:41.693Z,1566253181.693 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.194767
2019-08-19T22:19:41.788Z,1566253181.788 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:42.186Z,1566253182.186 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:42.641Z,1566253182.641 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:42.995Z,1566253182.995 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:43.445Z,1566253183.445 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:43.799Z,1566253183.799 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:44.212Z,1566253184.212 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:44.606Z,1566253184.606 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:45.030Z,1566253185.030 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:45.406Z,1566253185.406 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:45.835Z,1566253185.835 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:19:45.835Z,1566253185.835 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:19:45.835Z,1566253185.835 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:19:45.835Z,1566253185.835 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:19:45.836Z,1566253185.836 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:46.226Z,1566253186.226 [Default:CheckIn:D] Stopped
2019-08-19T22:19:46.226Z,1566253186.226 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:19:46.227Z,1566253186.227 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.869932 min 
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn:E] Stopped
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn] Stopped
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn](INFO): Running loop #6
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn] Running Loop=6
2019-08-19T22:19:46.666Z,1566253186.666 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:19:46.667Z,1566253186.667 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:19:46.667Z,1566253186.667 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:47.021Z,1566253187.021 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:47.457Z,1566253187.457 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:47.882Z,1566253187.882 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:48.253Z,1566253188.253 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:19:48.302Z,1566253188.302 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:48.658Z,1566253188.658 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:49.078Z,1566253189.078 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:49.466Z,1566253189.466 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:49.906Z,1566253189.906 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:50.230Z,1566253190.230 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-19T22:19:50.287Z,1566253190.287 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:50.702Z,1566253190.702 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:51.057Z,1566253191.057 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:19:51.086Z,1566253191.086 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:51.561Z,1566253191.561 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:51.902Z,1566253191.902 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:52.324Z,1566253192.324 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:52.726Z,1566253192.726 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:53.137Z,1566253193.137 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:53.495Z,1566253193.495 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:53.897Z,1566253193.897 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:19:53.942Z,1566253193.942 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:54.314Z,1566253194.314 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:54.742Z,1566253194.742 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:55.117Z,1566253195.117 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:55.544Z,1566253195.544 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:55.935Z,1566253195.935 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:56.332Z,1566253196.332 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:56.709Z,1566253196.709 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:19:56.738Z,1566253196.738 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:57.163Z,1566253197.163 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:57.541Z,1566253197.541 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:57.964Z,1566253197.964 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:58.357Z,1566253198.357 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:58.799Z,1566253198.799 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:59.173Z,1566253199.173 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:59.625Z,1566253199.625 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:19:59.937Z,1566253199.937 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:19:59.970Z,1566253199.970 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:00.394Z,1566253200.394 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:00.778Z,1566253200.778 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:01.190Z,1566253201.190 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:01.586Z,1566253201.586 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:02.018Z,1566253202.018 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:02.379Z,1566253202.379 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:02.789Z,1566253202.789 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:02.845Z,1566253202.845 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:03.206Z,1566253203.206 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:03.622Z,1566253203.622 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:04.061Z,1566253204.061 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:04.454Z,1566253204.454 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:04.807Z,1566253204.807 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:05.222Z,1566253205.222 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:05.597Z,1566253205.597 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:05.626Z,1566253205.626 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:06.050Z,1566253206.050 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:06.438Z,1566253206.438 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:06.862Z,1566253206.862 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:07.240Z,1566253207.240 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:07.666Z,1566253207.666 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:08.041Z,1566253208.041 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:08.080Z,1566253208.080 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:08.498Z,1566253208.498 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:08.862Z,1566253208.862 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:09.268Z,1566253209.268 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:09.682Z,1566253209.682 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:10.098Z,1566253210.098 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:10.454Z,1566253210.454 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:10.869Z,1566253210.869 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:10.925Z,1566253210.925 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:11.282Z,1566253211.282 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:11.702Z,1566253211.702 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:12.078Z,1566253212.078 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:12.499Z,1566253212.499 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:12.888Z,1566253212.888 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:13.318Z,1566253213.318 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:13.710Z,1566253213.710 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:14.097Z,1566253214.097 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:14.153Z,1566253214.153 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:14.514Z,1566253214.514 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:14.954Z,1566253214.954 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:15.314Z,1566253215.314 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:15.723Z,1566253215.723 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:16.123Z,1566253216.123 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:16.558Z,1566253216.558 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:16.905Z,1566253216.905 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:16.948Z,1566253216.948 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:17.393Z,1566253217.393 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:17.761Z,1566253217.761 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:18.154Z,1566253218.154 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:18.543Z,1566253218.543 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:18.965Z,1566253218.965 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:19.358Z,1566253219.358 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:19.779Z,1566253219.779 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:20.137Z,1566253220.137 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:20.174Z,1566253220.174 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:20.612Z,1566253220.612 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:21.021Z,1566253221.021 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:21.415Z,1566253221.415 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:21.771Z,1566253221.771 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:22.997Z,1566253222.997 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:24.620Z,1566253224.620 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:25.054Z,1566253225.054 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:25.435Z,1566253225.435 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:25.805Z,1566253225.805 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:25.834Z,1566253225.834 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:26.289Z,1566253226.289 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:26.661Z,1566253226.661 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-08-19T22:20:28.645Z,1566253228.645 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:31.949Z,1566253231.949 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:34.753Z,1566253234.753 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:37.985Z,1566253237.985 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:40.833Z,1566253240.833 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:42.697Z,1566253242.697 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:20:44.065Z,1566253244.065 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:46.877Z,1566253246.877 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:50.121Z,1566253250.121 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:52.937Z,1566253252.937 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:56.165Z,1566253256.165 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:20:59.017Z,1566253259.017 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:01.825Z,1566253261.825 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:04.665Z,1566253264.665 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:07.901Z,1566253267.901 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:10.709Z,1566253270.709 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:13.941Z,1566253273.941 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:16.789Z,1566253276.789 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:17.845Z,1566253277.845 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:21:20.013Z,1566253280.013 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:22.829Z,1566253282.829 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:26.077Z,1566253286.077 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:28.937Z,1566253288.937 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:32.161Z,1566253292.161 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:34.957Z,1566253294.957 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:38.185Z,1566253298.185 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:41.025Z,1566253301.025 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:43.837Z,1566253303.837 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:46.685Z,1566253306.685 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:49.913Z,1566253309.913 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:52.729Z,1566253312.729 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:52.993Z,1566253312.993 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:21:55.957Z,1566253315.957 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:21:58.837Z,1566253318.837 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:02.037Z,1566253322.037 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:04.849Z,1566253324.849 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:08.077Z,1566253328.077 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:10.937Z,1566253330.937 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:14.153Z,1566253334.153 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:16.969Z,1566253336.969 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:19.813Z,1566253339.813 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:23.045Z,1566253343.045 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:25.853Z,1566253345.853 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:28.141Z,1566253348.141 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:22:28.701Z,1566253348.701 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:31.937Z,1566253351.937 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:34.741Z,1566253354.741 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:37.977Z,1566253357.977 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:40.821Z,1566253360.821 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:44.053Z,1566253364.053 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:46.861Z,1566253366.861 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:50.093Z,1566253370.093 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:52.953Z,1566253372.953 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:56.185Z,1566253376.185 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:22:58.985Z,1566253378.985 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:01.829Z,1566253381.829 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:03.289Z,1566253383.289 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:23:04.637Z,1566253384.637 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:07.869Z,1566253387.869 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:10.713Z,1566253390.713 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:13.941Z,1566253393.941 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:16.757Z,1566253396.757 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:19.989Z,1566253399.989 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:22.833Z,1566253402.833 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:26.061Z,1566253406.061 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:28.877Z,1566253408.877 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:32.113Z,1566253412.113 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:34.961Z,1566253414.961 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:38.205Z,1566253418.205 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:38.437Z,1566253418.437 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:23:40.997Z,1566253420.997 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:43.845Z,1566253423.845 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:46.657Z,1566253426.657 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:49.885Z,1566253429.885 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:52.729Z,1566253432.729 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:55.961Z,1566253435.961 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:23:58.773Z,1566253438.773 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:02.009Z,1566253442.009 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:04.853Z,1566253444.853 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:08.113Z,1566253448.113 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:10.917Z,1566253450.917 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:13.585Z,1566253453.585 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:24:14.157Z,1566253454.157 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:16.953Z,1566253456.953 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:20.189Z,1566253460.189 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:23.041Z,1566253463.041 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:25.849Z,1566253465.849 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:28.685Z,1566253468.685 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:31.917Z,1566253471.917 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:34.737Z,1566253474.737 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:37.961Z,1566253477.961 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:40.805Z,1566253480.805 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:44.037Z,1566253484.037 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:46.845Z,1566253486.845 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:24:46.874Z,1566253486.874 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T22:19:46.7Z
2019-08-19T22:24:46.874Z,1566253486.874 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:24:46.874Z,1566253486.874 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:24:48.733Z,1566253488.733 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-19T22:25:00.633Z,1566253500.633 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.007722
2019-08-19T22:25:08.853Z,1566253508.853 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20190819T214719/Courier0022.lzma
2019-08-19T22:25:09.658Z,1566253509.658 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0022.lzma.bak
2019-08-19T22:25:09.658Z,1566253509.658 [DataOverHttps](INFO): SBD MOMSN=11593235
2019-08-19T22:25:26.938Z,1566253526.938 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20190819T214719/Express0023.lzma
2019-08-19T22:25:27.742Z,1566253527.742 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0023.lzma.bak
2019-08-19T22:25:27.742Z,1566253527.742 [DataOverHttps](INFO): SBD MOMSN=11593243
2019-08-19T22:25:32.892Z,1566253532.892 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:25:32.892Z,1566253532.892 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:25:32.897Z,1566253532.897 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:25:36.044Z,1566253536.044 [DVL_micro](ERROR): only read 44 of 46 data items
2019-08-19T22:25:36.044Z,1566253536.044 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 0 1 0.2 0 0 1.00 0 171.3 0 -320 -17 0 0 2 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 -6.74 -1.93 183.5 -2.0 18.6 .0 1489 82
2019-08-19T22:25:39.272Z,1566253539.272 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T22:25:40.844Z,1566253540.844 [CommandLine](IMPORTANT): got command configSet list
2019-08-19T22:25:40.844Z,1566253540.844 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-19T22:25:40.849Z,1566253540.849 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-08-19T22:25:40.849Z,1566253540.849 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-08-19T22:25:40.849Z,1566253540.849 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-19T22:25:40.849Z,1566253540.849 [CommandLine](IMPORTANT): PAR_Licor.darkCount=-15 count;

2019-08-19T22:25:40.850Z,1566253540.850 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-08-19T22:25:40.850Z,1566253540.850 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=250 cubic_centimeter;

2019-08-19T22:25:40.850Z,1566253540.850 [CommandLine](IMPORTANT): VerticalControl.massDefault=-11 millimeter;

2019-08-19T22:25:43.357Z,1566253543.357 [CommandLine](IMPORTANT): got command configSet list
2019-08-19T22:25:43.357Z,1566253543.357 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-19T22:25:43.358Z,1566253543.358 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-08-19T22:25:43.358Z,1566253543.358 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-08-19T22:25:43.358Z,1566253543.358 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-19T22:25:43.358Z,1566253543.358 [CommandLine](IMPORTANT): PAR_Licor.darkCount=-15 count;

2019-08-19T22:25:43.359Z,1566253543.359 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-08-19T22:25:43.359Z,1566253543.359 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=250 cubic_centimeter;

2019-08-19T22:25:43.359Z,1566253543.359 [CommandLine](IMPORTANT): VerticalControl.massDefault=-11 millimeter;

2019-08-19T22:26:13.630Z,1566253573.630 [DVL_micro](ERROR): only read 43 of 46 data items
2019-08-19T22:26:13.630Z,1566253573.630 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 0.2 0 1.0 1.2 -368.2 0 -388.1 319.4 0 18 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 -6.68 -1.99 187.5 0.2 18.6 0.005 35.0 1489 86
2019-08-19T22:30:07.605Z,1566253807.605 [DVL_micro](ERROR): checksum mismatch: reported106 , calculated:113
2019-08-19T22:30:07.605Z,1566253807.605 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 9.9 10.5 10.2 12.3 -98.5 51.4 -81 -36 152 -92 1 2 1 1 -0.7 -65.4 9.8 1 -6.6 63.5 17.3 1 -311 74 -15 2 317 -36 -15 2 -6.65 -1.94 187.0 9.9 18.6 0.005 35.0 1489 106
2019-08-19T22:30:33.559Z,1566253833.559 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:30:33.559Z,1566253833.559 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:30:33.559Z,1566253833.559 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:30:33.559Z,1566253833.559 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:30:33.888Z,1566253833.888 [Default:CheckIn:D] Stopped
2019-08-19T22:30:33.888Z,1566253833.888 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:30:34.310Z,1566253834.310 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.664303 min 
2019-08-19T22:30:34.310Z,1566253834.310 [Default:CheckIn:E] Stopped
2019-08-19T22:30:34.310Z,1566253834.310 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:30:34.310Z,1566253834.310 [Default:CheckIn] Stopped
2019-08-19T22:30:34.311Z,1566253834.311 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:30:34.311Z,1566253834.311 [Default:CheckIn](INFO): Running loop #7
2019-08-19T22:30:34.311Z,1566253834.311 [Default:CheckIn] Running Loop=7
2019-08-19T22:30:34.311Z,1566253834.311 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:30:34.311Z,1566253834.311 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:30:35.889Z,1566253835.889 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-08-19T22:30:35.889Z,1566253835.889 [NAL9602] Data Fault, FailCount= 1
2019-08-19T22:30:35.889Z,1566253835.889 [NAL9602](ERROR): Data Fault
2019-08-19T22:30:35.922Z,1566253835.922 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-19T22:30:36.280Z,1566253836.280 [NAL9602](INFO): Powering down
2019-08-19T22:30:37.126Z,1566253837.126 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-19T22:30:37.126Z,1566253837.126 [NAL9602] No Fault, FailCount= 1
2019-08-19T22:31:06.623Z,1566253866.623 [NAL9602](INFO): Powering up NAL9602
2019-08-19T22:31:17.492Z,1566253877.492 [NAL9602](INFO): NAL9602 initialized
2019-08-19T22:31:18.317Z,1566253878.317 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:31:59.914Z,1566253919.914 [DVL_micro](ERROR): only read 45 of 46 data items
2019-08-19T22:31:59.914Z,1566253919.914 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 9.9 10.6 10.2 0 8.0 11.2 13.4 0 -42 -11 -13 0 1 2 1 5 -7.2 1.3 11.5 1 7.9 -1.5 11.0 1 -38 -14 -17 2 36 20 -10 -1.99 188.1 9.9 18.6 0.005 35.0 1489 120
2019-08-19T22:32:33.438Z,1566253953.438 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-08-19T22:32:33.438Z,1566253953.438 [DropWeight] Hardware Fault, FailCount= 1
2019-08-19T22:32:33.438Z,1566253953.438 [DropWeight](ERROR): Hardware Fault
2019-08-19T22:32:33.516Z,1566253953.516 [CBIT](INFO): Critical error at 20190819T223233
2019-08-19T22:32:33.518Z,1566253953.518 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-08-19T22:32:33.519Z,1566253953.519 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-08-19T22:32:33.916Z,1566253953.916 [CBIT](INFO): Critical error at 20190819T223233
2019-08-19T22:35:34.507Z,1566254134.507 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T22:30:34.3Z
2019-08-19T22:35:34.507Z,1566254134.507 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:35:34.508Z,1566254134.508 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:35:42.360Z,1566254142.360 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20190819T214719/Courier0025.lzma
2019-08-19T22:35:43.166Z,1566254143.166 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0025.lzma.bak
2019-08-19T22:35:43.166Z,1566254143.166 [DataOverHttps](INFO): SBD MOMSN=11593271
2019-08-19T22:35:59.121Z,1566254159.121 [DataOverHttps](INFO): Sending 450 bytes from file Logs/20190819T214719/Express0026.lzma
2019-08-19T22:35:59.926Z,1566254159.926 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0026.lzma.bak
2019-08-19T22:35:59.926Z,1566254159.926 [DataOverHttps](INFO): SBD MOMSN=11593275
2019-08-19T22:36:06.432Z,1566254166.432 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:36:06.432Z,1566254166.432 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:36:06.437Z,1566254166.437 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:36:20.604Z,1566254180.604 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-19T22:36:51.287Z,1566254211.287 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T22:38:01.856Z,1566254281.856 [CommandLine](IMPORTANT): got command maintain clear
2019-08-19T22:38:02.086Z,1566254282.086 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,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-08-19T22:40:04.034Z,1566254404.034 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position
2019-08-19T22:41:07.123Z,1566254467.123 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:41:07.124Z,1566254467.124 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:41:07.124Z,1566254467.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:41:07.124Z,1566254467.124 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:41:07.483Z,1566254467.483 [Default:CheckIn:D] Stopped
2019-08-19T22:41:07.483Z,1566254467.483 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:41:07.907Z,1566254467.907 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.224211 min 
2019-08-19T22:41:07.907Z,1566254467.907 [Default:CheckIn:E] Stopped
2019-08-19T22:41:07.907Z,1566254467.907 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:41:07.907Z,1566254467.907 [Default:CheckIn] Stopped
2019-08-19T22:41:07.907Z,1566254467.907 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:41:07.907Z,1566254467.907 [Default:CheckIn](INFO): Running loop #8
2019-08-19T22:41:07.907Z,1566254467.907 [Default:CheckIn] Running Loop=8
2019-08-19T22:41:07.908Z,1566254467.908 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:41:07.908Z,1566254467.908 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:41:09.525Z,1566254469.525 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:41:09.886Z,1566254469.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223714.00,A,3648.16654,N,12147.28839,W,0.292,190.19,190819,,,A*7C
2019-08-19T22:41:09.888Z,1566254469.888 [NAL9602](INFO): GPS fix at 20190819T223714: (36.802776, -121.788140)
2019-08-19T22:41:09.974Z,1566254469.974 [UniversalFixResidualReporter](INFO): Fix residual: 25.2 %DT, over the last 867.6 m. Residual distance 218.9 m at bearing -129.6 degrees. Fix at (36.8028, -121.7881) with 14.5 m made good.
2019-08-19T22:41:09.975Z,1566254469.975 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:41:09.975Z,1566254469.975 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:41:14.322Z,1566254474.322 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20190819T214719/Courier0028.lzma
2019-08-19T22:41:15.141Z,1566254475.141 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0028.lzma.bak
2019-08-19T22:41:15.142Z,1566254475.142 [DataOverHttps](INFO): SBD MOMSN=11593297
2019-08-19T22:41:32.453Z,1566254492.453 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20190819T214719/Express0029.lzma
2019-08-19T22:41:33.259Z,1566254493.259 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0029.lzma.bak
2019-08-19T22:41:33.259Z,1566254493.259 [DataOverHttps](INFO): SBD MOMSN=11593300
2019-08-19T22:41:39.184Z,1566254499.184 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:41:39.184Z,1566254499.184 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:41:39.184Z,1566254499.184 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:41:40.765Z,1566254500.765 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-19T22:41:40.841Z,1566254500.841 [NAL9602](FAULT): received: 
+CSQ:0

OK2, 2, 0, 0, 0

OK
2019-08-19T22:41:40.841Z,1566254500.841 [NAL9602] Data Fault, FailCount= 2
2019-08-19T22:41:40.841Z,1566254500.841 [NAL9602](ERROR): Data Fault
2019-08-19T22:41:40.957Z,1566254500.957 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-19T22:41:41.143Z,1566254501.143 [NAL9602](INFO): Powering down
2019-08-19T22:41:42.012Z,1566254502.012 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-19T22:41:42.012Z,1566254502.012 [NAL9602] No Fault, FailCount= 2
2019-08-19T22:41:45.201Z,1566254505.201 [DVL_micro](ERROR): only read 45 of 46 data items
2019-08-19T22:41:45.202Z,1566254505.202 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 9.9 0 9.1 10.9 15.2 0 -78.9 -28.4 24 26 -64 44 1 4 1 1 125.6 -9.2 -34.4 1 -125.1 23.1 117 -24 8 2 -114 34 8 2 -6.66 -2.05 175.0 9.1 18.6 0.005 35.0 1489 122
2019-08-19T22:42:11.448Z,1566254531.448 [NAL9602](INFO): Powering up NAL9602
2019-08-19T22:42:22.362Z,1566254542.362 [NAL9602](INFO): NAL9602 initialized
2019-08-19T22:42:53.467Z,1566254573.467 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T22:44:29.232Z,1566254669.232 [DVL_micro](ERROR): only read 37 of 46 data items
2019-08-19T22:44:29.233Z,1566254669.233 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 0 1 10.1 10.4 0 9.4 -1.9 8.9 0 -3.1 57 95 0 94 1 2 5 1 -12.8 16.0 3.1 1 4.8 -20.1 1.0 1 2 -69 31 66 2 -6.76 5.0 9..005 35.0 1489 115
2019-08-19T22:44:51.394Z,1566254691.394 [DataOverHttps](IMPORTANT): SBD MTMSN=20190819T224056
2019-08-19T22:44:56.888Z,1566254696.888 [DataOverHttps](INFO): Received command:maintain remove platform_buoyancy_position
2019-08-19T22:44:57.759Z,1566254697.759 [CommandLine](IMPORTANT): got command maintain remove platform_buoyancy_position
2019-08-19T22:46:39.841Z,1566254799.841 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:46:39.841Z,1566254799.841 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:46:39.842Z,1566254799.842 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:46:39.842Z,1566254799.842 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:46:40.182Z,1566254800.182 [Default:CheckIn:D] Stopped
2019-08-19T22:46:40.182Z,1566254800.182 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:46:40.674Z,1566254800.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.769202 min 
2019-08-19T22:46:40.674Z,1566254800.674 [Default:CheckIn:E] Stopped
2019-08-19T22:46:40.674Z,1566254800.674 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:46:40.674Z,1566254800.674 [Default:CheckIn] Stopped
2019-08-19T22:46:40.674Z,1566254800.674 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:46:40.674Z,1566254800.674 [Default:CheckIn](INFO): Running loop #9
2019-08-19T22:46:40.674Z,1566254800.674 [Default:CheckIn] Running Loop=9
2019-08-19T22:46:40.675Z,1566254800.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:46:40.675Z,1566254800.675 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:46:42.233Z,1566254802.233 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:46:42.562Z,1566254802.562 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224246.00,A,3648.16498,N,12147.27939,W,0.117,0.00,190819,,,A*7B
2019-08-19T22:46:42.564Z,1566254802.564 [NAL9602](INFO): GPS fix at 20190819T224246: (36.802750, -121.787990)
2019-08-19T22:46:42.595Z,1566254802.595 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:46:42.595Z,1566254802.595 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:46:44.017Z,1566254804.017 [DVL_micro](ERROR): checksum mismatch: reported71 , calculated:68
2019-08-19T22:46:44.018Z,1566254804.018 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 5.6 4.2 1.6 -196.5 -163.5 84.6 0 0 0 0 0 0 0 -375.2 -183.0 -81.4 1 124.0 278.6 -296.5 1 0 0 0 0 0 0 0 0 -0.38 -38.62 208.8 0.2 18.6 0.005 35.0 1489 71
2019-08-19T22:46:44.416Z,1566254804.416 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-19T22:46:51.564Z,1566254811.564 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190819T214719/Courier0031.lzma
2019-08-19T22:46:52.370Z,1566254812.370 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0031.lzma.bak
2019-08-19T22:46:52.371Z,1566254812.371 [DataOverHttps](INFO): SBD MOMSN=11593319
2019-08-19T22:47:07.580Z,1566254827.580 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190819T214719/Courier0034.lzma
2019-08-19T22:47:08.386Z,1566254828.386 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0034.lzma.bak
2019-08-19T22:47:08.387Z,1566254828.387 [DataOverHttps](INFO): SBD MOMSN=11593322
2019-08-19T22:47:15.189Z,1566254835.189 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-19T22:47:25.938Z,1566254845.938 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20190819T214719/Express0032.lzma
2019-08-19T22:47:26.742Z,1566254846.742 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0032.lzma.bak
2019-08-19T22:47:26.743Z,1566254846.743 [DataOverHttps](INFO): SBD MOMSN=11593324
2019-08-19T22:47:33.798Z,1566254853.798 [CBIT](INFO): Clearing failed state for component DropWeight
2019-08-19T22:47:33.798Z,1566254853.798 [DropWeight] No Fault, FailCount= 1
2019-08-19T22:47:42.680Z,1566254862.680 [DataOverHttps](INFO): Sending 19 bytes from file Logs/20190819T214719/Express0036.lzma
2019-08-19T22:47:43.486Z,1566254863.486 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0036.lzma.bak
2019-08-19T22:47:43.487Z,1566254863.487 [DataOverHttps](INFO): SBD MOMSN=11593330
2019-08-19T22:47:48.280Z,1566254868.280 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:47:48.280Z,1566254868.280 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:47:48.280Z,1566254868.280 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:49:50.754Z,1566254990.754 [DataOverHttps](IMPORTANT): SBD MTMSN=20190819T224555
2019-08-19T22:49:56.120Z,1566254996.120 [DataOverHttps](INFO): Received command:report mod platform_buoyancy_position
2019-08-19T22:49:57.076Z,1566254997.076 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position
2019-08-19T22:51:07.374Z,1566255067.374 [DataOverHttps](IMPORTANT): SBD MTMSN=20190819T224712
2019-08-19T22:51:12.868Z,1566255072.868 [DataOverHttps](INFO): Received command:get platform_buoyancy_position
2019-08-19T22:51:13.781Z,1566255073.781 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2019-08-19T22:51:13.782Z,1566255073.782 [CommandLine](IMPORTANT): platform_buoyancy_position 200.000000 cc
2019-08-19T22:52:23.982Z,1566255143.982 [DataOverHttps](IMPORTANT): SBD MTMSN=20190819T224828
2019-08-19T22:52:29.676Z,1566255149.676 [DataOverHttps](INFO): Received command:maintain clear
2019-08-19T22:52:29.740Z,1566255149.740 [CommandLine](IMPORTANT): got command maintain clear
2019-08-19T22:52:47.378Z,1566255167.378 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2019-08-19T22:52:47.379Z,1566255167.379 [CommandLine](IMPORTANT): platform_buoyancy_position 200.000000 cc
2019-08-19T22:52:48.890Z,1566255168.890 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-19T22:52:48.890Z,1566255168.890 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:52:48.890Z,1566255168.890 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:52:48.890Z,1566255168.890 [Default:CheckIn:D] Running Loop=1
2019-08-19T22:52:49.325Z,1566255169.325 [Default:CheckIn:D] Stopped
2019-08-19T22:52:49.325Z,1566255169.325 [Default:CheckIn:E] Running Loop=1
2019-08-19T22:52:49.691Z,1566255169.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.921586 min 
2019-08-19T22:52:49.691Z,1566255169.691 [Default:CheckIn:E] Stopped
2019-08-19T22:52:49.692Z,1566255169.692 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-19T22:52:49.692Z,1566255169.692 [Default:CheckIn] Stopped
2019-08-19T22:52:49.692Z,1566255169.692 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:52:49.692Z,1566255169.692 [Default:CheckIn](INFO): Running loop #10
2019-08-19T22:52:49.692Z,1566255169.692 [Default:CheckIn] Running Loop=10
2019-08-19T22:52:49.692Z,1566255169.692 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-19T22:52:49.692Z,1566255169.692 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-19T22:52:51.297Z,1566255171.297 [NAL9602](DEBUG): Fix Requested
2019-08-19T22:52:51.709Z,1566255171.709 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224856.00,A,3648.16368,N,12147.28550,W,0.175,3.75,190819,,,A*71
2019-08-19T22:52:51.711Z,1566255171.711 [NAL9602](INFO): GPS fix at 20190819T224856: (36.802728, -121.788092)
2019-08-19T22:52:51.734Z,1566255171.734 [Default:CheckIn:Read_GPS] Stopped
2019-08-19T22:52:51.735Z,1566255171.735 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-19T22:52:57.618Z,1566255177.618 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2019-08-19T22:52:57.619Z,1566255177.619 [CommandLine](IMPORTANT): platform_buoyancy_position 200.000000 cc
2019-08-19T22:53:00.712Z,1566255180.712 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T214719/Courier0035.lzma
2019-08-19T22:53:01.514Z,1566255181.514 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0035.lzma.bak
2019-08-19T22:53:01.514Z,1566255181.514 [DataOverHttps](INFO): SBD MOMSN=11593338
2019-08-19T22:53:08.269Z,1566255188.269 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2019-08-19T22:53:08.269Z,1566255188.269 [CommandLine](IMPORTANT): platform_buoyancy_position 200.000000 cc
2019-08-19T22:53:18.516Z,1566255198.516 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T214719/Courier0040.lzma
2019-08-19T22:53:19.322Z,1566255199.322 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Courier0040.lzma.bak
2019-08-19T22:53:19.323Z,1566255199.323 [DataOverHttps](INFO): SBD MOMSN=11593340
2019-08-19T22:53:31.228Z,1566255211.228 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2019-08-19T22:53:31.229Z,1566255211.229 [CommandLine](IMPORTANT): platform_buoyancy_position 200.000000 cc
2019-08-19T22:53:35.577Z,1566255215.577 [DataOverHttps](INFO): Sending 353 bytes from file Logs/20190819T214719/Express0037.lzma
2019-08-19T22:53:36.382Z,1566255216.382 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0037.lzma.bak
2019-08-19T22:53:36.383Z,1566255216.383 [DataOverHttps](INFO): SBD MOMSN=11593342
2019-08-19T22:53:44.210Z,1566255224.210 [DVL_micro](ERROR): only read 45 of 46 data items
2019-08-19T22:53:44.210Z,1566255224.210 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 1 0.2 0 0.2 0.3 -319.3 0 -499.6 -3.4 0 -446 0 0 0 2 0 0 240.6 -1083.9 -441.6 1 -459.2 1047.7 -345.3 1 0 0 0 0 0 0 0 0 -4.42 -2.62 2 18.6 0.005 35.0 1489 103
2019-08-19T22:53:52.709Z,1566255232.709 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20190819T214719/Express0041.lzma
2019-08-19T22:53:54.896Z,1566255234.896 [DataOverHttps](INFO): Moved sent file to Logs/20190819T214719/Express0041.lzma.bak
2019-08-19T22:53:54.896Z,1566255234.896 [DataOverHttps](INFO): SBD MOMSN=11593355
2019-08-19T22:53:59.994Z,1566255239.994 [Default:CheckIn:Read_Iridium] Stopped
2019-08-19T22:53:59.994Z,1566255239.994 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-19T22:53:59.994Z,1566255239.994 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-19T22:54:18.078Z,1566255258.078 [DataOverHttps](IMPORTANT): SBD MTMSN=20190819T225022
2019-08-19T22:54:23.704Z,1566255263.704 [DataOverHttps](INFO): Received command:maintain remove platform_buoyancy_position
2019-08-19T22:54:24.672Z,1566255264.672 [CommandLine](IMPORTANT): got command maintain remove platform_buoyancy_position
2019-08-19T22:54:30.098Z,1566255270.098 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2019-08-19T22:54:30.098Z,1566255270.098 [CommandLine](IMPORTANT): platform_buoyancy_position 200.000000 cc
2019-08-19T22:54:40.693Z,1566255280.693 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2019-08-19T22:54:40.694Z,1566255280.694 [CommandLine](IMPORTANT): platform_buoyancy_position 200.000000 cc
2019-08-19T22:55:35.575Z,1566255335.575 [CommandLine](IMPORTANT): got command restart application
2019-08-19T22:55:36.582Z,1566255336.582 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:36.582Z,1566255336.582 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:36.737Z,1566255336.737 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-08-19T22:55:36.737Z,1566255336.737 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:36.738Z,1566255336.738 [CommandLine](INFO): Join timeout helper Thread ID is 5284
2019-08-19T22:55:36.738Z,1566255336.738 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-08-19T22:55:36.738Z,1566255336.738 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:36.739Z,1566255336.739 [NavChartDb](INFO): Join timeout helper Thread ID is 5285
2019-08-19T22:55:36.877Z,1566255336.877 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:36.877Z,1566255336.877 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:36.897Z,1566255336.897 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-08-19T22:55:36.897Z,1566255336.897 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:36.897Z,1566255336.897 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5286
2019-08-19T22:55:37.305Z,1566255337.305 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:37.305Z,1566255337.305 [WetLabsBB2FL](INFO): Powering down
2019-08-19T22:55:37.306Z,1566255337.306 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:37.321Z,1566255337.321 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-08-19T22:55:37.321Z,1566255337.321 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:37.321Z,1566255337.321 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5287
2019-08-19T22:55:37.965Z,1566255337.965 [CTD_Seabird](INFO): Powering down
2019-08-19T22:55:37.977Z,1566255337.977 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:37.977Z,1566255337.977 [CTD_Seabird](INFO): Powering down
2019-08-19T22:55:37.989Z,1566255337.989 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.001Z,1566255338.001 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-08-19T22:55:38.001Z,1566255338.001 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.001Z,1566255338.001 [Radio_Surface](INFO): Join timeout helper Thread ID is 5288
2019-08-19T22:55:38.053Z,1566255338.053 [Radio_Surface](INFO): Powering down
2019-08-19T22:55:38.054Z,1566255338.054 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:38.054Z,1566255338.054 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.062Z,1566255338.062 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-08-19T22:55:38.062Z,1566255338.062 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.062Z,1566255338.062 [DataOverHttps](INFO): Join timeout helper Thread ID is 5289
2019-08-19T22:55:38.333Z,1566255338.333 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:38.333Z,1566255338.333 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.338Z,1566255338.338 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-08-19T22:55:38.338Z,1566255338.338 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.338Z,1566255338.338 [logger](INFO): Join timeout helper Thread ID is 5290
2019-08-19T22:55:38.365Z,1566255338.365 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:38.365Z,1566255338.365 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.377Z,1566255338.377 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-08-19T22:55:38.378Z,1566255338.378 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.378Z,1566255338.378 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-08-19T22:55:38.378Z,1566255338.378 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.378Z,1566255338.378 [controlThread](INFO): Join timeout helper Thread ID is 5291
2019-08-19T22:55:38.561Z,1566255338.561 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-19T22:55:38.561Z,1566255338.561 [controlThread](DEBUG): Uninitializing ControlThread
2019-08-19T22:55:38.562Z,1566255338.562 [AHRS_M2](INFO): Powering down
2019-08-19T22:55:38.705Z,1566255338.705 [DVL_micro](INFO): uninitialize:Powering down
2019-08-19T22:55:38.706Z,1566255338.706 [NAL9602](INFO): Powering down
2019-08-19T22:55:38.708Z,1566255338.708 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-08-19T22:55:38.709Z,1566255338.709 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-08-19T22:55:38.709Z,1566255338.709 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-08-19T22:55:38.710Z,1566255338.710 [MissionManager](INFO): Uninitializing Mission Default
2019-08-19T22:55:38.710Z,1566255338.710 [Default] Stopped
2019-08-19T22:55:38.710Z,1566255338.710 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-19T22:55:38.710Z,1566255338.710 [Default:B.GoToSurface] Stopped
2019-08-19T22:55:38.710Z,1566255338.710 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-19T22:55:38.710Z,1566255338.710 [Default:CheckIn] Stopped
2019-08-19T22:55:38.710Z,1566255338.710 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-19T22:55:38.710Z,1566255338.710 [Default:CheckIn:C.Wait] Stopped
2019-08-19T22:55:38.710Z,1566255338.710 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-19T22:55:38.713Z,1566255338.713 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-08-19T22:55:38.713Z,1566255338.713 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-08-19T22:55:38.713Z,1566255338.713 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-08-19T22:55:38.714Z,1566255338.714 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-08-19T22:55:38.714Z,1566255338.714 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-08-19T22:55:38.714Z,1566255338.714 [BuoyancyServo](INFO): Powering down
2019-08-19T22:55:38.729Z,1566255338.729 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-08-19T22:55:38.729Z,1566255338.729 [ElevatorServo](INFO): Powering down
2019-08-19T22:55:38.730Z,1566255338.730 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-08-19T22:55:38.730Z,1566255338.730 [MassServo](INFO): Powering down
2019-08-19T22:55:38.731Z,1566255338.731 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-19T22:55:38.731Z,1566255338.731 [RudderServo](INFO): Powering down
2019-08-19T22:55:38.732Z,1566255338.732 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-08-19T22:55:38.732Z,1566255338.732 [ThrusterServo](INFO): Powering down
2019-08-19T22:55:38.732Z,1566255338.732 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-08-19T22:55:38.733Z,1566255338.733 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-08-19T22:55:38.733Z,1566255338.733 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-08-19T22:55:38.733Z,1566255338.733 [CBIT](DEBUG): Powering off loads.
2019-08-19T22:55:38.745Z,1566255338.745 [CBIT](DEBUG): Disabling WDT.
2019-08-19T22:55:38.757Z,1566255338.757 [CBIT](DEBUG): Opening all GF detection circuits.
2019-08-19T22:55:38.758Z,1566255338.758 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.841Z,1566255338.841 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.850Z,1566255338.850 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.884Z,1566255338.884 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.887Z,1566255338.887 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.918Z,1566255338.918 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-19T22:55:38.985Z,1566255338.985 [logger ThreadHandler](INFO): Thread cancelled.