2019-08-21T18:56:05.422Z,1566413765.422 [Supervisor](DEBUG): Initializing supervisor. 2019-08-21T18:56:05.425Z,1566413765.425 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-08-21T18:56:05.425Z,1566413765.425 [SyncHandler](INFO): Protected caller Thread ID is 807 2019-08-21T18:56:05.426Z,1566413765.426 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-08-21T18:56:05.426Z,1566413765.426 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-08-21T18:56:05.427Z,1566413765.427 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 808 2019-08-21T18:56:05.429Z,1566413765.429 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-08-21T18:56:05.441Z,1566413765.441 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-08-21T18:56:05.442Z,1566413765.442 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-08-21T18:56:05.442Z,1566413765.442 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 809 2019-08-21T18:56:05.443Z,1566413765.443 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-08-21T18:56:05.444Z,1566413765.444 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-08-21T18:56:05.445Z,1566413765.445 [logger ThreadHandler](INFO): Protected caller Thread ID is 810 2019-08-21T18:56:05.447Z,1566413765.447 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-08-21T18:56:05.447Z,1566413765.447 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-08-21T18:56:05.451Z,1566413765.451 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-08-21T18:56:05.878Z,1566413765.878 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-08-21T18:56:05.879Z,1566413765.879 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-08-21T18:56:06.023Z,1566413766.023 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-08-21T18:56:06.025Z,1566413766.025 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-08-21T18:56:06.105Z,1566413766.105 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-08-21T18:56:06.205Z,1566413766.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-08-21T18:56:06.207Z,1566413766.207 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-08-21T18:56:06.302Z,1566413766.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-08-21T18:56:06.304Z,1566413766.304 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-08-21T18:56:06.686Z,1566413766.686 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-08-21T18:56:06.686Z,1566413766.686 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-08-21T18:56:06.790Z,1566413766.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-08-21T18:56:06.791Z,1566413766.791 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-08-21T18:56:07.266Z,1566413767.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-08-21T18:56:07.267Z,1566413767.267 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-08-21T18:56:07.469Z,1566413767.469 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-08-21T18:56:07.470Z,1566413767.470 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-08-21T18:56:07.775Z,1566413767.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-08-21T18:56:07.777Z,1566413767.777 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-08-21T18:56:07.991Z,1566413767.991 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-08-21T18:56:07.991Z,1566413767.991 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-08-21T18:56:08.134Z,1566413768.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-08-21T18:56:08.135Z,1566413768.135 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-08-21T18:56:08.759Z,1566413768.759 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-08-21T18:56:08.905Z,1566413768.905 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-08-21T18:56:09.854Z,1566413769.854 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-08-21T18:56:09.856Z,1566413769.856 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-08-21T18:56:10.106Z,1566413770.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-08-21T18:56:10.108Z,1566413770.108 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2019-08-21T18:56:10.112Z,1566413770.112 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2019-08-21T18:56:10.186Z,1566413770.186 [Config/vehicle](CRITICAL): Attempting to set a string configuration value to the non-string configuration: DVL_micro.baud 2019-08-21T18:56:10.297Z,1566413770.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2019-08-21T18:56:10.380Z,1566413770.380 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2019-08-21T18:56:10.498Z,1566413770.498 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2019-08-21T18:56:10.584Z,1566413770.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2019-08-21T18:56:10.815Z,1566413770.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-08-21T18:56:10.817Z,1566413770.817 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2019-08-21T18:56:10.911Z,1566413770.911 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2019-08-21T18:56:11.020Z,1566413771.020 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2019-08-21T18:56:11.114Z,1566413771.114 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2019-08-21T18:56:11.262Z,1566413771.262 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2019-08-21T18:56:11.363Z,1566413771.363 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2019-08-21T18:56:11.462Z,1566413771.462 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2019-08-21T18:56:11.464Z,1566413771.464 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-08-21T18:56:11.489Z,1566413771.489 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-08-21T18:56:11.490Z,1566413771.490 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-08-21T18:56:11.578Z,1566413771.578 [VerticalControl](DEBUG): Construct VerticalControl. 2019-08-21T18:56:11.693Z,1566413771.693 [VerticalControl] Loaded 2019-08-21T18:56:11.693Z,1566413771.693 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-08-21T18:56:11.694Z,1566413771.694 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-08-21T18:56:11.764Z,1566413771.764 [HorizontalControl] Loaded 2019-08-21T18:56:11.764Z,1566413771.764 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-08-21T18:56:11.765Z,1566413771.765 [SpeedControl](DEBUG): Construct SpeedControl. 2019-08-21T18:56:11.770Z,1566413771.770 [SpeedControl] Loaded 2019-08-21T18:56:11.771Z,1566413771.771 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-08-21T18:56:11.771Z,1566413771.771 [LoopControl](DEBUG): Construct LoopControl. 2019-08-21T18:56:11.772Z,1566413771.772 [LoopControl] Loaded 2019-08-21T18:56:11.772Z,1566413771.772 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-08-21T18:56:11.773Z,1566413771.773 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-08-21T18:56:11.773Z,1566413771.773 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-08-21T18:56:11.927Z,1566413771.927 [BuoyancyServo] Loaded 2019-08-21T18:56:11.927Z,1566413771.927 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-08-21T18:56:11.938Z,1566413771.938 [ElevatorServo] Loaded 2019-08-21T18:56:11.939Z,1566413771.939 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-08-21T18:56:11.950Z,1566413771.950 [MassServo] Loaded 2019-08-21T18:56:11.950Z,1566413771.950 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-08-21T18:56:11.961Z,1566413771.961 [RudderServo] Loaded 2019-08-21T18:56:11.961Z,1566413771.961 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-08-21T18:56:11.972Z,1566413771.972 [ThrusterServo] Loaded 2019-08-21T18:56:11.972Z,1566413771.972 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-08-21T18:56:11.973Z,1566413771.973 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-08-21T18:56:11.974Z,1566413771.974 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-08-21T18:56:12.029Z,1566413772.029 [DepthRateCalculator] Loaded 2019-08-21T18:56:12.029Z,1566413772.029 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-08-21T18:56:12.034Z,1566413772.034 [PitchRateCalculator] Loaded 2019-08-21T18:56:12.035Z,1566413772.035 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-08-21T18:56:12.050Z,1566413772.050 [SpeedCalculator] Loaded 2019-08-21T18:56:12.050Z,1566413772.050 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-08-21T18:56:12.072Z,1566413772.072 [TempGradientCalculator] Loaded 2019-08-21T18:56:12.072Z,1566413772.072 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-08-21T18:56:12.077Z,1566413772.077 [YawRateCalculator] Loaded 2019-08-21T18:56:12.077Z,1566413772.077 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-08-21T18:56:12.107Z,1566413772.107 [ElevatorOffsetCalculator] Loaded 2019-08-21T18:56:12.107Z,1566413772.107 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-08-21T18:56:12.107Z,1566413772.107 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-08-21T18:56:12.108Z,1566413772.108 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-08-21T18:56:12.231Z,1566413772.231 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-08-21T18:56:12.231Z,1566413772.231 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-08-21T18:56:12.252Z,1566413772.252 [NavChart] Loaded 2019-08-21T18:56:12.252Z,1566413772.252 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-08-21T18:56:12.256Z,1566413772.256 [UniversalFixResidualReporter] Loaded 2019-08-21T18:56:12.256Z,1566413772.256 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-08-21T18:56:12.257Z,1566413772.257 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-08-21T18:56:12.258Z,1566413772.258 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-08-21T18:56:12.953Z,1566413772.953 [AHRS_M2] Loaded 2019-08-21T18:56:12.953Z,1566413772.953 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-08-21T18:56:13.095Z,1566413773.095 [DataOverHttps] Loaded 2019-08-21T18:56:13.096Z,1566413773.096 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-08-21T18:56:13.097Z,1566413773.097 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408094E0 2019-08-21T18:56:13.097Z,1566413773.097 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 889 2019-08-21T18:56:13.111Z,1566413773.111 [Depth_Keller] Loaded 2019-08-21T18:56:13.111Z,1566413773.111 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-08-21T18:56:13.116Z,1566413773.116 [DropWeight] Loaded 2019-08-21T18:56:13.116Z,1566413773.116 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-08-21T18:56:13.247Z,1566413773.247 [DVL_micro] Loaded 2019-08-21T18:56:13.247Z,1566413773.247 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-08-21T18:56:13.345Z,1566413773.345 [NAL9602] Loaded 2019-08-21T18:56:13.345Z,1566413773.345 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-08-21T18:56:13.362Z,1566413773.362 [Onboard] Loaded 2019-08-21T18:56:13.362Z,1566413773.362 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-08-21T18:56:13.365Z,1566413773.365 [Radio_Surface] Loaded 2019-08-21T18:56:13.366Z,1566413773.366 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-08-21T18:56:13.367Z,1566413773.367 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408394E0 2019-08-21T18:56:13.367Z,1566413773.367 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 890 2019-08-21T18:56:14.947Z,1566413774.947 [BPC1] Loaded 2019-08-21T18:56:14.947Z,1566413774.947 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-08-21T18:56:14.948Z,1566413774.948 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-08-21T18:56:14.948Z,1566413774.948 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-08-21T18:56:15.397Z,1566413775.397 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-08-21T18:56:15.398Z,1566413775.398 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-08-21T18:56:15.799Z,1566413775.799 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-08-21T18:56:15.799Z,1566413775.799 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-08-21T18:56:15.849Z,1566413775.849 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-08-21T18:56:15.850Z,1566413775.850 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-08-21T18:56:16.176Z,1566413776.176 [CTD_NeilBrown] Loaded 2019-08-21T18:56:16.176Z,1566413776.176 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2019-08-21T18:56:16.177Z,1566413776.177 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409CF4E0 2019-08-21T18:56:16.178Z,1566413776.178 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 892 2019-08-21T18:56:16.187Z,1566413776.187 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-08-21T18:56:16.192Z,1566413776.192 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-08-21T18:56:16.194Z,1566413776.194 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-08-21T18:56:16.199Z,1566413776.199 [CTD_Seabird](INFO): created writer for : depth 2019-08-21T18:56:16.199Z,1566413776.199 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-08-21T18:56:16.204Z,1566413776.204 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-08-21T18:56:16.205Z,1566413776.205 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-08-21T18:56:16.210Z,1566413776.210 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-08-21T18:56:16.210Z,1566413776.210 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-08-21T18:56:16.216Z,1566413776.216 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-08-21T18:56:16.216Z,1566413776.216 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-08-21T18:56:16.222Z,1566413776.222 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-08-21T18:56:16.222Z,1566413776.222 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-08-21T18:56:16.227Z,1566413776.227 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-08-21T18:56:16.255Z,1566413776.255 [CTD_Seabird] Loaded 2019-08-21T18:56:16.255Z,1566413776.255 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-08-21T18:56:16.256Z,1566413776.256 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409FF4E0 2019-08-21T18:56:16.256Z,1566413776.256 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 893 2019-08-21T18:56:16.271Z,1566413776.271 [PAR_Licor] Loaded 2019-08-21T18:56:16.272Z,1566413776.272 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-08-21T18:56:16.320Z,1566413776.320 [WetLabsBB2FL] Loaded 2019-08-21T18:56:16.320Z,1566413776.320 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-08-21T18:56:16.321Z,1566413776.321 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A2F4E0 2019-08-21T18:56:16.322Z,1566413776.322 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 894 2019-08-21T18:56:16.322Z,1566413776.322 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-08-21T18:56:16.323Z,1566413776.323 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-08-21T18:56:16.674Z,1566413776.674 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-08-21T18:56:16.676Z,1566413776.676 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-08-21T18:56:16.838Z,1566413776.838 [SBIT](DEBUG): Construct Startup Built In Test. 2019-08-21T18:56:16.850Z,1566413776.850 [SBIT] Loaded 2019-08-21T18:56:16.850Z,1566413776.850 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-08-21T18:56:16.851Z,1566413776.851 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-08-21T18:56:16.863Z,1566413776.863 [IBIT] Loaded 2019-08-21T18:56:16.863Z,1566413776.863 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-08-21T18:56:16.866Z,1566413776.866 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-08-21T18:56:17.009Z,1566413777.009 [CBIT] Loaded 2019-08-21T18:56:17.010Z,1566413777.010 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-08-21T18:56:17.010Z,1566413777.010 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-08-21T18:56:17.014Z,1566413777.014 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-08-21T18:56:17.014Z,1566413777.014 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-08-21T18:56:17.021Z,1566413777.021 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-08-21T18:56:17.022Z,1566413777.022 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0 2019-08-21T18:56:17.022Z,1566413777.022 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 895 2019-08-21T18:56:17.027Z,1566413777.027 [Supervisor](INFO): Main Thread ID is 803 2019-08-21T18:56:17.027Z,1566413777.027 [Supervisor](DEBUG): Running supervisor. 2019-08-21T18:56:17.028Z,1566413777.028 [CommandLine ThreadHandler](INFO): Handler Thread ID is 896 2019-08-21T18:56:17.030Z,1566413777.030 [controlThread ThreadHandler](INFO): Handler Thread ID is 897 2019-08-21T18:56:17.031Z,1566413777.031 [controlThread](DEBUG): Initializing ControlThread 2019-08-21T18:56:17.031Z,1566413777.031 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-08-21T18:56:17.033Z,1566413777.033 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-08-21T18:56:17.034Z,1566413777.034 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-08-21T18:56:17.034Z,1566413777.034 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-08-21T18:56:17.035Z,1566413777.035 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-08-21T18:56:17.036Z,1566413777.036 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-08-21T18:56:17.036Z,1566413777.036 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-08-21T18:56:17.036Z,1566413777.036 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-08-21T18:56:17.037Z,1566413777.037 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-08-21T18:56:17.037Z,1566413777.037 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-08-21T18:56:17.038Z,1566413777.038 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-08-21T18:56:17.039Z,1566413777.039 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-08-21T18:56:17.045Z,1566413777.045 [SBIT](INFO): Initialize SBIT Component. 2019-08-21T18:56:17.046Z,1566413777.046 [SBIT](IMPORTANT): git: 2019-07-01-A 2019-08-21T18:56:17.046Z,1566413777.046 [SBIT](INFO): git hash: 0265b1445bf28f06bbb263eff661be182b07029c 2019-08-21T18:56:17.046Z,1566413777.046 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-08-21T18:56:17.047Z,1566413777.047 [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-21T18:56:17.048Z,1566413777.048 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2019-08-21T18:56:17.049Z,1566413777.049 [IBIT](INFO): Initialize IBIT Component. 2019-08-21T18:56:17.050Z,1566413777.050 [CBIT](DEBUG): Initialize CBIT Component. 2019-08-21T18:56:17.051Z,1566413777.051 [logger ThreadHandler](INFO): Handler Thread ID is 898 2019-08-21T18:56:17.061Z,1566413777.061 [CBIT](DEBUG): Initialized mux pins. 2019-08-21T18:56:17.061Z,1566413777.061 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2019-08-21T18:56:17.061Z,1566413777.061 [CBIT](DEBUG): Initializing the watchdog timer. 2019-08-21T18:56:17.069Z,1566413777.069 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 899 2019-08-21T18:56:17.071Z,1566413777.071 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-08-21T18:56:17.073Z,1566413777.073 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 901 2019-08-21T18:56:17.074Z,1566413777.074 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 902 2019-08-21T18:56:17.076Z,1566413777.076 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-08-21T18:56:17.078Z,1566413777.078 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 904 2019-08-21T18:56:17.079Z,1566413777.079 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 905 2019-08-21T18:56:17.081Z,1566413777.081 [WetLabsBB2FL](INFO): Powering down 2019-08-21T18:56:17.097Z,1566413777.097 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-08-21T18:56:17.097Z,1566413777.097 [CBIT](DEBUG): Initializing heartbeat. 2019-08-21T18:56:17.105Z,1566413777.105 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-08-21T18:56:17.109Z,1566413777.109 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 900 2019-08-21T18:56:17.169Z,1566413777.169 [CBIT](DEBUG): Deactivating GF circuits. 2019-08-21T18:56:17.169Z,1566413777.169 [CBIT](DEBUG): Deactivating emergency mode. 2019-08-21T18:56:17.205Z,1566413777.205 [CBIT](DEBUG): Backplane powered. 2019-08-21T18:56:17.206Z,1566413777.206 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-08-21T18:56:17.513Z,1566413777.513 [Radio_Surface](INFO): Powering up 2019-08-21T18:56:17.618Z,1566413777.618 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-21T18:56:17.633Z,1566413777.633 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-08-21T18:56:17.633Z,1566413777.633 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-08-21T18:56:17.633Z,1566413777.633 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-08-21T18:56:17.633Z,1566413777.633 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-08-21T18:56:17.633Z,1566413777.633 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-08-21T18:56:17.633Z,1566413777.633 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-08-21T18:56:17.634Z,1566413777.634 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-08-21T18:56:17.634Z,1566413777.634 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-08-21T18:56:17.634Z,1566413777.634 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-08-21T18:56:17.634Z,1566413777.634 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-08-21T18:56:17.634Z,1566413777.634 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-08-21T18:56:17.635Z,1566413777.635 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-08-21T18:56:17.635Z,1566413777.635 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-08-21T18:56:17.635Z,1566413777.635 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-08-21T18:56:17.635Z,1566413777.635 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-08-21T18:56:17.635Z,1566413777.635 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-08-21T18:56:17.654Z,1566413777.654 [MissionManager](DEBUG): 2019-08-21T18:56:17.655Z,1566413777.655 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-08-21T18:56:17.721Z,1566413777.721 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-08-21T18:56:17.722Z,1566413777.722 [Default:A.Wait](DEBUG): Construct Wait. 2019-08-21T18:56:17.724Z,1566413777.724 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-21T18:56:17.754Z,1566413777.754 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-08-21T18:56:17.777Z,1566413777.777 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-08-21T18:56:17.782Z,1566413777.782 [Default:E.Execute](DEBUG): Construct Execute. 2019-08-21T18:56:17.802Z,1566413777.802 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-08-21T18:56:17.806Z,1566413777.806 [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-21T18:56:17.811Z,1566413777.811 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-08-21T18:56:17.942Z,1566413777.942 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar 2019-08-21T18:56:17.965Z,1566413777.965 [DVL_micro](INFO): Initializing 2019-08-21T18:56:18.057Z,1566413778.057 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-08-21T18:56:18.098Z,1566413778.098 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-08-21T18:56:18.105Z,1566413778.105 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-08-21T18:56:18.106Z,1566413778.106 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-08-21T18:56:18.113Z,1566413778.113 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-08-21T18:56:18.114Z,1566413778.114 [MassServo](DEBUG): Initializing EZServoServo. 2019-08-21T18:56:18.121Z,1566413778.121 [MassServo](DEBUG): Initializing MassServo. 2019-08-21T18:56:18.122Z,1566413778.122 [RudderServo](DEBUG): Initializing EZServoServo. 2019-08-21T18:56:18.129Z,1566413778.129 [RudderServo](DEBUG): Initializing RudderServo. 2019-08-21T18:56:18.130Z,1566413778.130 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-08-21T18:56:18.137Z,1566413778.137 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-08-21T18:56:18.139Z,1566413778.139 [CommandLine](FAULT): Scheduling is paused 2019-08-21T18:56:18.139Z,1566413778.139 [CBIT](INFO): Critical error at 20190821T185610 2019-08-21T18:56:18.140Z,1566413778.140 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-08-21T18:56:18.339Z,1566413778.339 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2019-08-21T18:56:18.339Z,1566413778.339 [DropWeight] Hardware Fault, FailCount= 1 2019-08-21T18:56:18.339Z,1566413778.339 [DropWeight](ERROR): Hardware Fault 2019-08-21T18:56:18.387Z,1566413778.387 [CBIT](INFO): Critical error at 20190821T185618 2019-08-21T18:56:18.389Z,1566413778.389 [CBIT](ERROR): Hardware Fault in component: DropWeight 2019-08-21T18:56:18.390Z,1566413778.390 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2019-08-21T18:56:19.017Z,1566413779.017 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-08-21T18:56:19.017Z,1566413779.017 [RudderServo](FAULT): Rudder failed to initialize 2019-08-21T18:56:19.017Z,1566413779.017 [RudderServo] Communications Fault, FailCount= 1 2019-08-21T18:56:19.017Z,1566413779.017 [RudderServo](ERROR): Communications Fault 2019-08-21T18:56:19.162Z,1566413779.162 [CBIT](INFO): Critical error at 20190821T185618 2019-08-21T18:56:19.164Z,1566413779.164 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-08-21T18:56:19.378Z,1566413779.378 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-21T18:56:19.378Z,1566413779.378 [RudderServo](INFO): Powering down 2019-08-21T18:56:20.051Z,1566413780.051 [RudderServo](DEBUG): Initializing EZServoServo. 2019-08-21T18:56:20.170Z,1566413780.170 [RudderServo](DEBUG): Initializing RudderServo. 2019-08-21T18:56:20.174Z,1566413780.174 [CBIT](INFO): Clearing failed state for component RudderServo 2019-08-21T18:56:20.174Z,1566413780.174 [RudderServo] No Fault, FailCount= 1 2019-08-21T18:56:25.109Z,1566413785.109 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2019-08-21T18:56:43.415Z,1566413803.415 [NAL9602](INFO): Powering up NAL9602 2019-08-21T18:56:45.494Z,1566413805.494 [SBIT](IMPORTANT): Beginning Startup BIT 2019-08-21T18:56:45.538Z,1566413805.538 [CBIT](IMPORTANT): Beginning ground fault scan 2019-08-21T18:56:50.388Z,1566413810.388 [DVL_micro](ERROR): only read 44 of 46 data items 2019-08-21T18:56:50.389Z,1566413810.389 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 1428 272 317 312 2 2 2 2 1482.8 -53.4 627.9 2 933.0 1153.7 627.9 2 1482 -53 627 2 933 1153 627 2 19.52 -1.17 53.1 -3.0 19.8 0.005 35.0 2019-08-21T18:56:54.415Z,1566413814.415 [NAL9602](INFO): NAL9602 initialized 2019-08-21T18:56:55.237Z,1566413815.237 [NAL9602](DEBUG): Fix Requested 2019-08-21T18:56:56.498Z,1566413816.498 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.069054 CHAN A1 (24V): -0.025615 CHAN A2 (12V): 0.033422 CHAN A3 (5V): -0.003364 CHAN B0 (3.3V): 0.001028 CHAN B1 (3.15aV): 0.003594 CHAN B2 (3.15bV): 0.004501 CHAN B3 (GND): 0.000638 OPEN: 0.002295 Full Scale Calc: 4.765 mA, -1.589 mA 2019-08-21T18:57:29.019Z,1566413849.019 [DVL_micro](ERROR): only read 45 of 46 data items 2019-08-21T18:57:29.019Z,1566413849.019 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 315 323 337 2 2 2 2 109.4 -29.4 372.1 2 88.8 70.3 372.1 2 109 -29 372 2 88 70 372 2 19.50 -1.20 53.4 -3.0 19.8 0.005 35.0 1489 102 2019-08-21T18:57:38.896Z,1566413858.896 [SBIT](IMPORTANT): SBIT PASSED 2019-08-21T18:57:38.981Z,1566413858.981 [CommandLine](IMPORTANT): got command configSet list 2019-08-21T18:57:38.982Z,1566413858.982 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-08-21T18:57:38.982Z,1566413858.982 [CommandLine](IMPORTANT): No configSet variables persisted 2019-08-21T18:57:39.175Z,1566413859.175 [MissionManager](IMPORTANT): Started mission Startup 2019-08-21T18:57:39.175Z,1566413859.175 [Startup] Running Loop=1 2019-08-21T18:57:39.175Z,1566413859.175 [Startup](DEBUG): Aggregate::initialize Startup 2019-08-21T18:57:39.175Z,1566413859.175 [Startup:A.GoToSurface] Running Loop=1 2019-08-21T18:57:39.175Z,1566413859.175 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-21T18:57:39.176Z,1566413859.176 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-21T18:57:39.176Z,1566413859.176 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-21T18:57:39.177Z,1566413859.177 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-21T18:57:39.177Z,1566413859.177 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-21T18:57:39.178Z,1566413859.178 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-21T18:57:39.179Z,1566413859.179 [Startup:StartupSatComms] Running Loop=1 2019-08-21T18:57:39.179Z,1566413859.179 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-08-21T18:57:39.179Z,1566413859.179 [Startup:StartupSatComms:A] Running Loop=1 2019-08-21T18:57:39.579Z,1566413859.579 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-08-21T18:58:39.335Z,1566413919.335 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-21T18:57:39.2Z 2019-08-21T18:58:39.335Z,1566413919.335 [Startup:StartupSatComms:A] Stopped 2019-08-21T18:58:39.335Z,1566413919.335 [Startup:StartupSatComms:B] Running Loop=1 2019-08-21T18:58:39.491Z,1566413919.491 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004992 2019-08-21T18:58:39.740Z,1566413919.740 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-21T18:58:44.441Z,1566413924.441 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20190821T185605/Courier0000.lzma 2019-08-21T18:58:45.242Z,1566413925.242 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Courier0000.lzma.bak 2019-08-21T18:58:45.243Z,1566413925.243 [DataOverHttps](INFO): SBD MOMSN=11657760 2019-08-21T18:58:55.998Z,1566413935.998 [DataOverHttps](INFO): Sending 689 bytes from file Logs/20190821T185605/Express0001.lzma 2019-08-21T18:58:56.804Z,1566413936.804 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Express0001.lzma.bak 2019-08-21T18:58:56.805Z,1566413936.805 [DataOverHttps](INFO): SBD MOMSN=11657766 2019-08-21T18:58:57.515Z,1566413937.515 [Startup:StartupSatComms:B] Stopped 2019-08-21T18:58:57.515Z,1566413937.515 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-08-21T18:58:57.515Z,1566413937.515 [Startup:StartupSatComms] Stopped 2019-08-21T18:58:57.515Z,1566413937.515 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-08-21T18:58:57.516Z,1566413937.516 [Startup](INFO): Completed Startup 2019-08-21T18:58:57.516Z,1566413937.516 [MissionManager](INFO): Startup is completed. 2019-08-21T18:58:57.516Z,1566413937.516 [MissionManager](INFO): Uninitializing Mission Startup 2019-08-21T18:58:57.516Z,1566413937.516 [Startup] Stopped 2019-08-21T18:58:57.516Z,1566413937.516 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-08-21T18:58:57.516Z,1566413937.516 [Startup:A.GoToSurface] Stopped 2019-08-21T18:58:57.516Z,1566413937.516 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-21T18:58:57.947Z,1566413937.947 [MissionManager](IMPORTANT): Started mission Default 2019-08-21T18:58:57.947Z,1566413937.947 [Default] Running Loop=1 2019-08-21T18:58:57.947Z,1566413937.947 [Default](DEBUG): Aggregate::initialize Default 2019-08-21T18:58:57.947Z,1566413937.947 [Default:B.GoToSurface] Running Loop=1 2019-08-21T18:58:57.947Z,1566413937.947 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-21T18:58:57.948Z,1566413937.948 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-21T18:58:57.948Z,1566413937.948 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-21T18:58:57.948Z,1566413937.948 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-21T18:58:57.949Z,1566413937.949 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-21T18:58:57.949Z,1566413937.949 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-21T18:58:57.950Z,1566413937.950 [Default:A.Wait] Running Loop=1 2019-08-21T18:58:57.950Z,1566413937.950 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-08-21T18:59:11.249Z,1566413951.249 [Default:A.Wait](INFO): Done Waiting. 2019-08-21T18:59:11.249Z,1566413951.249 [Default:A.Wait] Stopped 2019-08-21T18:59:11.250Z,1566413951.250 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-08-21T18:59:11.659Z,1566413951.659 [Default:CheckIn] Running Loop=1 2019-08-21T18:59:11.659Z,1566413951.659 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-21T18:59:11.659Z,1566413951.659 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-21T18:59:12.066Z,1566413952.066 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-08-21T18:59:17.310Z,1566413957.310 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-08-21T18:59:17.310Z,1566413957.310 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T18:59:17.321Z,1566413957.321 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T18:59:17.724Z,1566413957.724 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T18:59:17.724Z,1566413957.724 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-08-21T18:59:22.134Z,1566413962.134 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T18:59:22.134Z,1566413962.134 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T18:59:22.134Z,1566413962.134 [DVL_micro](ERROR): Data Fault 2019-08-21T18:59:22.192Z,1566413962.192 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T18:59:22.601Z,1566413962.601 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T18:59:23.396Z,1566413963.396 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T18:59:23.396Z,1566413963.396 [DVL_micro] No Fault, FailCount= 1 2019-08-21T18:59:23.752Z,1566413963.752 [DVL_micro](INFO): Initializing 2019-08-21T19:00:34.069Z,1566414034.069 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2019-08-21T19:01:57.267Z,1566414117.267 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-21T19:01:58.093Z,1566414118.093 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:01:59.706Z,1566414119.706 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:02:02.533Z,1566414122.533 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:05.377Z,1566414125.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:07.385Z,1566414127.385 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:10.629Z,1566414130.629 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:11.449Z,1566414131.449 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:02:13.441Z,1566414133.441 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:16.673Z,1566414136.673 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:18.345Z,1566414138.345 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-08-21T19:02:18.345Z,1566414138.345 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:02:18.355Z,1566414138.355 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:02:18.714Z,1566414138.714 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:02:18.715Z,1566414138.715 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-08-21T19:02:19.501Z,1566414139.501 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:22.333Z,1566414142.333 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:22.751Z,1566414142.751 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:02:24.353Z,1566414144.353 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:26.369Z,1566414146.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:27.978Z,1566414147.978 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:02:27.978Z,1566414147.978 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:02:27.978Z,1566414147.978 [DVL_micro](ERROR): Data Fault 2019-08-21T19:02:28.032Z,1566414148.032 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:02:28.449Z,1566414148.449 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:02:29.254Z,1566414149.254 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:02:29.254Z,1566414149.254 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:02:29.592Z,1566414149.592 [DVL_micro](INFO): Initializing 2019-08-21T19:02:29.613Z,1566414149.613 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:32.425Z,1566414152.425 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:34.045Z,1566414154.045 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:02:35.669Z,1566414155.669 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:38.489Z,1566414158.489 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:41.725Z,1566414161.725 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:44.549Z,1566414164.549 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:45.379Z,1566414165.379 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:02:47.377Z,1566414167.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:50.609Z,1566414170.609 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:53.437Z,1566414173.437 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:56.270Z,1566414176.270 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:02:56.669Z,1566414176.669 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:02:59.501Z,1566414179.501 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:02.325Z,1566414182.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:04.345Z,1566414184.345 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:07.573Z,1566414187.573 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:07.995Z,1566414187.995 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:03:10.405Z,1566414190.405 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:13.645Z,1566414193.645 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:16.465Z,1566414196.465 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:19.297Z,1566414199.297 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:03:19.697Z,1566414199.697 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:22.532Z,1566414202.532 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:25.361Z,1566414205.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:27.373Z,1566414207.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:30.605Z,1566414210.605 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:30.619Z,1566414210.619 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:03:33.437Z,1566414213.437 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:36.665Z,1566414216.665 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:39.493Z,1566414219.493 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:41.514Z,1566414221.514 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:03:42.729Z,1566414222.729 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:45.557Z,1566414225.557 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:48.385Z,1566414228.385 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:51.613Z,1566414231.613 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:53.240Z,1566414233.240 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:03:54.445Z,1566414234.445 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:03:57.677Z,1566414237.677 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:00.509Z,1566414240.509 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:03.349Z,1566414243.349 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:04.546Z,1566414244.546 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:04:05.353Z,1566414245.353 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:07.369Z,1566414247.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:10.609Z,1566414250.609 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:11.827Z,1566414251.827 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-21T18:59:11.7Z 2019-08-21T19:04:11.827Z,1566414251.827 [Default:CheckIn:Read_GPS] Stopped 2019-08-21T19:04:11.827Z,1566414251.827 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-21T19:04:12.231Z,1566414252.231 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-21T19:04:13.441Z,1566414253.441 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:15.454Z,1566414255.454 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:04:16.685Z,1566414256.685 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:17.092Z,1566414257.092 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190821T185605/Courier0004.lzma 2019-08-21T19:04:17.898Z,1566414257.898 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Courier0004.lzma.bak 2019-08-21T19:04:17.899Z,1566414257.899 [DataOverHttps](INFO): SBD MOMSN=11657852 2019-08-21T19:04:19.505Z,1566414259.505 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:22.733Z,1566414262.733 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:25.549Z,1566414265.549 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:28.377Z,1566414268.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:28.837Z,1566414268.837 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20190821T185605/Express0005.lzma 2019-08-21T19:04:29.642Z,1566414269.642 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Express0005.lzma.bak 2019-08-21T19:04:29.643Z,1566414269.643 [DataOverHttps](INFO): SBD MOMSN=11657854 2019-08-21T19:04:30.411Z,1566414270.411 [Default:CheckIn:Read_Iridium] Stopped 2019-08-21T19:04:30.411Z,1566414270.411 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-21T19:04:30.411Z,1566414270.411 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-21T19:04:31.609Z,1566414271.609 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:34.437Z,1566414274.437 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:37.669Z,1566414277.669 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:40.501Z,1566414280.501 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:43.325Z,1566414283.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:45.377Z,1566414285.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:47.369Z,1566414287.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:50.601Z,1566414290.601 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:53.429Z,1566414293.429 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:56.657Z,1566414296.657 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:04:59.485Z,1566414299.485 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:02.313Z,1566414302.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:04.340Z,1566414304.340 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:06.353Z,1566414306.353 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:08.373Z,1566414308.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:11.609Z,1566414311.609 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:14.453Z,1566414314.453 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:17.689Z,1566414317.689 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:19.292Z,1566414319.292 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-08-21T19:05:19.292Z,1566414319.292 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:05:19.302Z,1566414319.302 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:05:19.707Z,1566414319.707 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:05:19.707Z,1566414319.707 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-08-21T19:05:20.497Z,1566414320.497 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:23.325Z,1566414323.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:25.345Z,1566414325.345 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:27.373Z,1566414327.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:29.381Z,1566414329.381 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:32.617Z,1566414332.617 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:33.814Z,1566414333.814 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:05:33.814Z,1566414333.814 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:05:33.814Z,1566414333.814 [DVL_micro](ERROR): Data Fault 2019-08-21T19:05:33.861Z,1566414333.861 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:05:34.297Z,1566414334.297 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:05:35.136Z,1566414335.136 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:05:35.136Z,1566414335.136 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:05:35.436Z,1566414335.436 [DVL_micro](INFO): Initializing 2019-08-21T19:05:35.449Z,1566414335.449 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:38.677Z,1566414338.677 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:41.497Z,1566414341.497 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:44.333Z,1566414344.333 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:47.565Z,1566414347.565 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:50.389Z,1566414350.389 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:53.621Z,1566414353.621 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:56.449Z,1566414356.449 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:05:59.681Z,1566414359.681 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:02.509Z,1566414362.509 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:05.337Z,1566414365.337 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:07.357Z,1566414367.357 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:09.377Z,1566414369.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:12.609Z,1566414372.609 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:15.449Z,1566414375.449 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:18.685Z,1566414378.685 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:21.505Z,1566414381.505 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:24.341Z,1566414384.341 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:26.357Z,1566414386.357 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:29.589Z,1566414389.589 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:32.421Z,1566414392.421 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:35.650Z,1566414395.650 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:38.473Z,1566414398.473 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:41.709Z,1566414401.709 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:44.533Z,1566414404.533 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:47.361Z,1566414407.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:50.593Z,1566414410.593 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:53.417Z,1566414413.417 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:06:56.640Z,1566414416.640 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-21T19:06:56.640Z,1566414416.640 [NAL9602] Data Fault, FailCount= 1 2019-08-21T19:06:56.640Z,1566414416.640 [NAL9602](ERROR): Data Fault 2019-08-21T19:06:56.719Z,1566414416.719 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-21T19:06:57.050Z,1566414417.050 [NAL9602](INFO): Powering down 2019-08-21T19:06:57.885Z,1566414417.885 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-21T19:06:57.885Z,1566414417.885 [NAL9602] No Fault, FailCount= 1 2019-08-21T19:07:27.343Z,1566414447.343 [NAL9602](INFO): Powering up NAL9602 2019-08-21T19:07:38.269Z,1566414458.269 [NAL9602](INFO): NAL9602 initialized 2019-08-21T19:07:39.073Z,1566414459.073 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:07:41.509Z,1566414461.509 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:07:44.329Z,1566414464.329 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:07:47.557Z,1566414467.557 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:07:50.389Z,1566414470.389 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:07:53.209Z,1566414473.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:07:55.233Z,1566414475.233 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:07:57.257Z,1566414477.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:00.481Z,1566414480.481 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:03.321Z,1566414483.321 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:06.541Z,1566414486.541 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:09.377Z,1566414489.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:12.201Z,1566414492.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:14.221Z,1566414494.221 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:16.237Z,1566414496.237 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:19.473Z,1566414499.473 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:20.325Z,1566414500.325 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-08-21T19:08:20.325Z,1566414500.325 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:08:20.335Z,1566414500.335 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:08:20.727Z,1566414500.727 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:08:20.728Z,1566414500.728 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-08-21T19:08:22.313Z,1566414502.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:25.537Z,1566414505.537 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:28.365Z,1566414508.365 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:31.600Z,1566414511.600 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:34.425Z,1566414514.425 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:37.249Z,1566414517.249 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:39.658Z,1566414519.658 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:08:39.658Z,1566414519.658 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:08:39.658Z,1566414519.658 [DVL_micro](ERROR): Data Fault 2019-08-21T19:08:39.716Z,1566414519.716 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:08:40.133Z,1566414520.133 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:08:40.481Z,1566414520.481 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:40.940Z,1566414520.940 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:08:40.940Z,1566414520.940 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:08:41.284Z,1566414521.284 [DVL_micro](INFO): Initializing 2019-08-21T19:08:43.309Z,1566414523.309 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:46.537Z,1566414526.537 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:49.369Z,1566414529.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:52.617Z,1566414532.617 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:55.433Z,1566414535.433 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:08:58.257Z,1566414538.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:01.493Z,1566414541.493 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:04.313Z,1566414544.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:07.549Z,1566414547.549 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:10.389Z,1566414550.389 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:13.213Z,1566414553.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:15.232Z,1566414555.232 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:17.245Z,1566414557.245 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:20.473Z,1566414560.473 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:23.325Z,1566414563.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:26.549Z,1566414566.549 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:29.365Z,1566414569.365 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:30.995Z,1566414570.995 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-21T19:09:30.995Z,1566414570.995 [Default:CheckIn:C.Wait] Stopped 2019-08-21T19:09:30.995Z,1566414570.995 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-21T19:09:30.995Z,1566414570.995 [Default:CheckIn:D] Running Loop=1 2019-08-21T19:09:31.400Z,1566414571.400 [Default:CheckIn:D] Stopped 2019-08-21T19:09:31.400Z,1566414571.400 [Default:CheckIn:E] Running Loop=1 2019-08-21T19:09:31.812Z,1566414571.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.557546 min 2019-08-21T19:09:31.813Z,1566414571.813 [Default:CheckIn:E] Stopped 2019-08-21T19:09:31.813Z,1566414571.813 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-21T19:09:31.813Z,1566414571.813 [Default:CheckIn] Stopped 2019-08-21T19:09:31.813Z,1566414571.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-21T19:09:31.813Z,1566414571.813 [Default:CheckIn](INFO): Running loop #2 2019-08-21T19:09:31.813Z,1566414571.813 [Default:CheckIn] Running Loop=2 2019-08-21T19:09:31.814Z,1566414571.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-21T19:09:31.814Z,1566414571.814 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-21T19:09:32.597Z,1566414572.597 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:35.434Z,1566414575.434 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:38.257Z,1566414578.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:41.489Z,1566414581.489 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:44.313Z,1566414584.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:47.545Z,1566414587.545 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:50.373Z,1566414590.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:53.205Z,1566414593.205 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:55.225Z,1566414595.225 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:57.245Z,1566414597.245 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:09:59.265Z,1566414599.265 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:02.505Z,1566414602.505 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:05.333Z,1566414605.333 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:08.565Z,1566414608.565 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:11.377Z,1566414611.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:14.209Z,1566414614.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:16.229Z,1566414616.229 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:18.261Z,1566414618.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:21.493Z,1566414621.493 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:24.309Z,1566414624.309 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:27.541Z,1566414627.541 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:30.369Z,1566414630.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:33.197Z,1566414633.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:35.217Z,1566414635.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:37.237Z,1566414637.237 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:40.465Z,1566414640.465 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:43.301Z,1566414643.301 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:46.529Z,1566414646.529 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:49.361Z,1566414649.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:52.589Z,1566414652.589 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:55.421Z,1566414655.421 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:10:58.245Z,1566414658.245 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:01.477Z,1566414661.477 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:04.305Z,1566414664.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:07.537Z,1566414667.537 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:10.361Z,1566414670.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:13.209Z,1566414673.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:15.213Z,1566414675.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:17.237Z,1566414677.237 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:18.471Z,1566414678.471 [CBIT](INFO): Clearing failed state for component DropWeight 2019-08-21T19:11:18.472Z,1566414678.472 [DropWeight] No Fault, FailCount= 1 2019-08-21T19:11:19.261Z,1566414679.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:19.658Z,1566414679.658 [DVL_micro](ERROR): checksum mismatch: reported110 , calculated:116 2019-08-21T19:11:19.659Z,1566414679.659 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 457 300 386 479 2 2 2 2 94.8 -238.9 437.3 2 249.2 -62 2 94 -238 437 2 249 -62 437 2 19.48 -1.23 54.2 -3.0 20.1 0.005 35.0 1489 110 2019-08-21T19:11:21.286Z,1566414681.286 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-08-21T19:11:21.286Z,1566414681.286 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:11:21.296Z,1566414681.296 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:11:21.770Z,1566414681.770 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:11:21.770Z,1566414681.770 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-08-21T19:11:22.489Z,1566414682.489 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:25.313Z,1566414685.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:28.557Z,1566414688.557 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:31.373Z,1566414691.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:34.201Z,1566414694.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:36.221Z,1566414696.221 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:38.241Z,1566414698.241 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:41.473Z,1566414701.473 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:44.301Z,1566414704.301 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:45.502Z,1566414705.502 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:11:45.502Z,1566414705.502 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:11:45.503Z,1566414705.503 [DVL_micro](ERROR): Data Fault 2019-08-21T19:11:45.559Z,1566414705.559 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:11:45.977Z,1566414705.977 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:11:46.747Z,1566414706.747 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:11:46.747Z,1566414706.747 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:11:47.124Z,1566414707.124 [DVL_micro](INFO): Initializing 2019-08-21T19:11:47.533Z,1566414707.533 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:49.157Z,1566414709.157 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:11:50.365Z,1566414710.365 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:53.609Z,1566414713.609 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:56.421Z,1566414716.421 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:11:59.261Z,1566414719.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:00.463Z,1566414720.463 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:12:02.485Z,1566414722.485 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:05.313Z,1566414725.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:08.541Z,1566414728.541 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:11.369Z,1566414731.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:12.191Z,1566414732.191 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:12:14.201Z,1566414734.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:16.241Z,1566414736.241 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:18.237Z,1566414738.237 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:20.261Z,1566414740.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:23.489Z,1566414743.489 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:23.919Z,1566414743.919 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:12:26.329Z,1566414746.329 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:29.565Z,1566414749.565 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:32.389Z,1566414752.389 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:35.205Z,1566414755.205 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:35.219Z,1566414755.219 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:12:37.229Z,1566414757.229 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:39.257Z,1566414759.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:42.485Z,1566414762.485 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:45.317Z,1566414765.317 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:46.528Z,1566414766.528 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:12:48.549Z,1566414768.549 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:51.369Z,1566414771.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:54.597Z,1566414774.597 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:57.425Z,1566414777.425 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:12:57.859Z,1566414777.859 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:13:00.269Z,1566414780.269 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:03.493Z,1566414783.493 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:06.317Z,1566414786.317 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:08.743Z,1566414788.743 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:13:09.545Z,1566414789.545 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:12.373Z,1566414792.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:15.205Z,1566414795.205 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:17.225Z,1566414797.225 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:19.241Z,1566414799.241 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:20.064Z,1566414800.064 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:13:22.473Z,1566414802.473 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:25.301Z,1566414805.301 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:28.537Z,1566414808.537 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:31.373Z,1566414811.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:31.388Z,1566414811.388 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:13:34.597Z,1566414814.597 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:37.421Z,1566414817.421 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:40.261Z,1566414820.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:42.679Z,1566414822.679 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:13:43.493Z,1566414823.493 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:46.313Z,1566414826.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:49.541Z,1566414829.541 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:52.377Z,1566414832.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:53.990Z,1566414833.990 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:13:55.201Z,1566414835.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:57.217Z,1566414837.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:13:59.237Z,1566414839.237 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:02.469Z,1566414842.469 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:05.297Z,1566414845.297 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:05.719Z,1566414845.719 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:14:08.529Z,1566414848.529 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:11.357Z,1566414851.357 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:14.589Z,1566414854.589 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:17.421Z,1566414857.421 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:20.245Z,1566414860.245 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:22.290Z,1566414862.290 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2019-08-21T19:14:22.290Z,1566414862.290 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:14:22.300Z,1566414862.300 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:14:22.760Z,1566414862.760 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:14:22.760Z,1566414862.760 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2019-08-21T19:14:23.481Z,1566414863.481 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:26.305Z,1566414866.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:29.541Z,1566414869.541 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:32.018Z,1566414872.018 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-21T19:09:31.8Z 2019-08-21T19:14:32.018Z,1566414872.018 [Default:CheckIn:Read_GPS] Stopped 2019-08-21T19:14:32.018Z,1566414872.018 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-21T19:14:32.381Z,1566414872.381 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:33.588Z,1566414873.588 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190821T185605/Courier0007.lzma 2019-08-21T19:14:34.394Z,1566414874.394 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Courier0007.lzma.bak 2019-08-21T19:14:34.394Z,1566414874.394 [DataOverHttps](INFO): SBD MOMSN=11657939 2019-08-21T19:14:35.269Z,1566414875.269 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:38.517Z,1566414878.517 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:41.317Z,1566414881.317 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:44.545Z,1566414884.545 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:46.073Z,1566414886.073 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20190821T185605/Express0008.lzma 2019-08-21T19:14:46.878Z,1566414886.878 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Express0008.lzma.bak 2019-08-21T19:14:46.878Z,1566414886.878 [DataOverHttps](INFO): SBD MOMSN=11657941 2019-08-21T19:14:47.373Z,1566414887.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:47.411Z,1566414887.411 [Default:CheckIn:Read_Iridium] Stopped 2019-08-21T19:14:47.411Z,1566414887.411 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-21T19:14:47.411Z,1566414887.411 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-21T19:14:50.201Z,1566414890.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:51.398Z,1566414891.398 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:14:51.398Z,1566414891.398 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:14:51.398Z,1566414891.398 [DVL_micro](ERROR): Data Fault 2019-08-21T19:14:51.462Z,1566414891.462 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:14:51.885Z,1566414891.885 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:14:52.225Z,1566414892.225 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:52.667Z,1566414892.667 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:14:52.667Z,1566414892.667 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:14:53.024Z,1566414893.024 [DVL_micro](INFO): Initializing 2019-08-21T19:14:54.241Z,1566414894.241 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:14:57.473Z,1566414897.473 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:00.305Z,1566414900.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:03.533Z,1566414903.533 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:06.361Z,1566414906.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:09.605Z,1566414909.605 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:12.433Z,1566414912.433 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:15.249Z,1566414915.249 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:18.485Z,1566414918.485 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:21.309Z,1566414921.309 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:24.541Z,1566414924.541 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:27.369Z,1566414927.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:30.213Z,1566414930.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:32.217Z,1566414932.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:34.237Z,1566414934.237 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:37.469Z,1566414937.469 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:40.301Z,1566414940.301 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:43.533Z,1566414943.533 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:46.361Z,1566414946.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:49.589Z,1566414949.589 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:52.417Z,1566414952.417 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:55.249Z,1566414955.249 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:15:58.477Z,1566414958.477 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:01.305Z,1566414961.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:04.537Z,1566414964.537 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:07.389Z,1566414967.389 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:10.197Z,1566414970.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:12.213Z,1566414972.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:14.233Z,1566414974.233 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:17.473Z,1566414977.473 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:20.305Z,1566414980.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:23.537Z,1566414983.537 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:26.357Z,1566414986.357 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:29.585Z,1566414989.585 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:32.417Z,1566414992.417 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:35.241Z,1566414995.241 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:38.481Z,1566414998.481 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:41.305Z,1566415001.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:44.541Z,1566415004.541 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:47.361Z,1566415007.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:50.189Z,1566415010.189 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:52.209Z,1566415012.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:54.233Z,1566415014.233 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:56.249Z,1566415016.249 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:16:59.481Z,1566415019.481 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:02.333Z,1566415022.333 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:05.561Z,1566415025.561 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:08.369Z,1566415028.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:11.197Z,1566415031.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:14.433Z,1566415034.433 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:17.261Z,1566415037.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:20.489Z,1566415040.489 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:23.321Z,1566415043.321 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:23.347Z,1566415043.347 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2019-08-21T19:17:23.347Z,1566415043.347 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:17:23.373Z,1566415043.373 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:17:23.755Z,1566415043.755 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:17:23.755Z,1566415043.755 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2019-08-21T19:17:26.553Z,1566415046.553 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:29.381Z,1566415049.381 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:32.205Z,1566415052.205 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:34.225Z,1566415054.225 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:36.245Z,1566415056.245 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:17:39.463Z,1566415059.463 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-21T19:17:39.463Z,1566415059.463 [NAL9602] Data Fault, FailCount= 2 2019-08-21T19:17:39.463Z,1566415059.463 [NAL9602](ERROR): Data Fault 2019-08-21T19:17:39.524Z,1566415059.524 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-21T19:17:39.867Z,1566415059.867 [NAL9602](INFO): Powering down 2019-08-21T19:17:40.775Z,1566415060.775 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-21T19:17:40.775Z,1566415060.775 [NAL9602] No Fault, FailCount= 2 2019-08-21T19:17:57.242Z,1566415077.242 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:17:57.242Z,1566415077.242 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:17:57.242Z,1566415077.242 [DVL_micro](ERROR): Data Fault 2019-08-21T19:17:57.355Z,1566415077.355 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:17:57.717Z,1566415077.717 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:17:58.503Z,1566415078.503 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:17:58.503Z,1566415078.503 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:17:58.860Z,1566415078.860 [DVL_micro](INFO): Initializing 2019-08-21T19:18:10.177Z,1566415090.177 [NAL9602](INFO): Powering up NAL9602 2019-08-21T19:18:21.075Z,1566415101.075 [NAL9602](INFO): NAL9602 initialized 2019-08-21T19:18:21.897Z,1566415101.897 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:24.329Z,1566415104.329 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:27.153Z,1566415107.153 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:30.381Z,1566415110.381 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:33.213Z,1566415113.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:36.441Z,1566415116.441 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:39.273Z,1566415119.273 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:42.105Z,1566415122.105 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:45.333Z,1566415125.333 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:48.161Z,1566415128.161 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:51.397Z,1566415131.397 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:54.217Z,1566415134.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:57.057Z,1566415137.057 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:18:59.069Z,1566415139.069 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:01.085Z,1566415141.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:04.317Z,1566415144.317 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:07.145Z,1566415147.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:10.377Z,1566415150.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:13.221Z,1566415153.221 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:16.036Z,1566415156.036 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:18.053Z,1566415158.053 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:20.073Z,1566415160.073 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:22.093Z,1566415162.093 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:25.325Z,1566415165.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:28.153Z,1566415168.153 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:31.385Z,1566415171.385 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:34.217Z,1566415174.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:37.049Z,1566415177.049 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:39.085Z,1566415179.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:41.085Z,1566415181.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:44.317Z,1566415184.317 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:47.145Z,1566415187.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:47.990Z,1566415187.990 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-21T19:19:47.990Z,1566415187.990 [Default:CheckIn:C.Wait] Stopped 2019-08-21T19:19:47.990Z,1566415187.990 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-21T19:19:47.990Z,1566415187.990 [Default:CheckIn:D] Running Loop=1 2019-08-21T19:19:48.364Z,1566415188.364 [Default:CheckIn:D] Stopped 2019-08-21T19:19:48.364Z,1566415188.364 [Default:CheckIn:E] Running Loop=1 2019-08-21T19:19:48.783Z,1566415188.783 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.840277 min 2019-08-21T19:19:48.783Z,1566415188.783 [Default:CheckIn:E] Stopped 2019-08-21T19:19:48.783Z,1566415188.783 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-21T19:19:48.784Z,1566415188.784 [Default:CheckIn] Stopped 2019-08-21T19:19:48.784Z,1566415188.784 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-21T19:19:48.784Z,1566415188.784 [Default:CheckIn](INFO): Running loop #3 2019-08-21T19:19:48.784Z,1566415188.784 [Default:CheckIn] Running Loop=3 2019-08-21T19:19:48.784Z,1566415188.784 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-21T19:19:48.784Z,1566415188.784 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-21T19:19:50.377Z,1566415190.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:53.209Z,1566415193.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:56.029Z,1566415196.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:19:58.049Z,1566415198.049 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:00.069Z,1566415200.069 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:02.089Z,1566415202.089 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:05.321Z,1566415205.321 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:08.189Z,1566415208.189 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:11.413Z,1566415211.413 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:14.209Z,1566415214.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:17.037Z,1566415217.037 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:19.061Z,1566415219.061 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:21.097Z,1566415221.097 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:23.101Z,1566415223.101 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:24.335Z,1566415224.335 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2019-08-21T19:20:24.335Z,1566415224.335 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:20:24.345Z,1566415224.345 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:20:24.797Z,1566415224.797 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:20:24.797Z,1566415224.797 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2019-08-21T19:20:26.329Z,1566415226.329 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:29.161Z,1566415229.161 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:32.389Z,1566415232.389 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:35.225Z,1566415235.225 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:38.049Z,1566415238.049 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:40.085Z,1566415240.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:42.081Z,1566415242.081 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:45.320Z,1566415245.320 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:48.153Z,1566415248.153 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:51.385Z,1566415251.385 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:54.205Z,1566415254.205 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:57.033Z,1566415257.033 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:20:59.057Z,1566415259.057 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:01.073Z,1566415261.073 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:03.078Z,1566415263.078 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:21:03.078Z,1566415263.078 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:21:03.078Z,1566415263.078 [DVL_micro](ERROR): Data Fault 2019-08-21T19:21:03.093Z,1566415263.093 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:03.162Z,1566415263.162 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:21:03.557Z,1566415263.557 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:21:04.327Z,1566415264.327 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:21:04.327Z,1566415264.327 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:21:04.700Z,1566415264.700 [DVL_micro](INFO): Initializing 2019-08-21T19:21:06.325Z,1566415266.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:09.161Z,1566415269.161 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:12.397Z,1566415272.397 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:15.213Z,1566415275.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:18.041Z,1566415278.041 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:20.065Z,1566415280.065 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:23.293Z,1566415283.293 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:26.121Z,1566415286.121 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:29.357Z,1566415289.357 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:32.181Z,1566415292.181 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:35.413Z,1566415295.413 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:35.831Z,1566415295.831 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:21:38.241Z,1566415298.241 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:41.085Z,1566415301.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:44.301Z,1566415304.301 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:47.145Z,1566415307.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:47.558Z,1566415307.558 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:21:50.365Z,1566415310.365 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:53.209Z,1566415313.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:56.453Z,1566415316.453 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:21:58.850Z,1566415318.850 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:21:59.253Z,1566415319.253 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:02.077Z,1566415322.077 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:05.313Z,1566415325.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:08.141Z,1566415328.141 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:10.165Z,1566415330.165 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:22:11.373Z,1566415331.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:14.208Z,1566415334.208 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:17.433Z,1566415337.433 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:20.257Z,1566415340.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:21.878Z,1566415341.878 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:22:23.085Z,1566415343.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:26.313Z,1566415346.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:29.145Z,1566415349.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:32.377Z,1566415352.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:33.203Z,1566415353.203 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:22:35.221Z,1566415355.221 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:38.041Z,1566415358.041 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:40.053Z,1566415360.053 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:42.097Z,1566415362.097 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:44.506Z,1566415364.506 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:22:45.317Z,1566415365.317 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:48.157Z,1566415368.157 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:51.385Z,1566415371.385 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:54.193Z,1566415374.193 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:22:55.813Z,1566415375.813 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:22:57.429Z,1566415377.429 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:00.253Z,1566415380.253 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:03.081Z,1566415383.081 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:06.313Z,1566415386.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:07.544Z,1566415387.544 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:23:09.145Z,1566415389.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:12.377Z,1566415392.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:15.217Z,1566415395.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:18.029Z,1566415398.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:18.857Z,1566415398.857 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:23:20.053Z,1566415400.053 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:22.069Z,1566415402.069 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:24.097Z,1566415404.097 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:25.366Z,1566415405.366 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2019-08-21T19:23:25.366Z,1566415405.366 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:23:25.376Z,1566415405.376 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:23:25.739Z,1566415405.739 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:23:25.739Z,1566415405.739 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2019-08-21T19:23:27.325Z,1566415407.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:30.165Z,1566415410.165 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:30.194Z,1566415410.194 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:23:33.409Z,1566415413.409 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:36.209Z,1566415416.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:39.053Z,1566415419.053 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:41.057Z,1566415421.057 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:41.480Z,1566415421.480 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:23:43.101Z,1566415423.101 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:46.337Z,1566415426.337 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:49.137Z,1566415429.137 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:52.369Z,1566415432.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:53.199Z,1566415433.199 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-08-21T19:23:55.197Z,1566415435.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:23:58.429Z,1566415438.429 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:01.261Z,1566415441.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:04.089Z,1566415444.089 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:07.321Z,1566415447.321 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:08.922Z,1566415448.922 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:24:08.922Z,1566415448.922 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:24:08.923Z,1566415448.923 [DVL_micro](ERROR): Data Fault 2019-08-21T19:24:08.954Z,1566415448.954 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:24:09.393Z,1566415449.393 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:24:10.149Z,1566415450.149 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:10.184Z,1566415450.184 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:24:10.184Z,1566415450.184 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:24:10.540Z,1566415450.540 [DVL_micro](INFO): Initializing 2019-08-21T19:24:13.380Z,1566415453.380 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:16.209Z,1566415456.209 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:19.033Z,1566415459.033 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:21.053Z,1566415461.053 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:23.073Z,1566415463.073 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:25.097Z,1566415465.097 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:28.329Z,1566415468.329 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:31.153Z,1566415471.153 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:34.385Z,1566415474.385 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:37.217Z,1566415477.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:40.045Z,1566415480.045 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:42.061Z,1566415482.061 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:45.297Z,1566415485.297 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:48.133Z,1566415488.133 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:48.986Z,1566415488.986 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-21T19:19:48.8Z 2019-08-21T19:24:48.987Z,1566415488.987 [Default:CheckIn:Read_GPS] Stopped 2019-08-21T19:24:48.987Z,1566415488.987 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-21T19:24:50.808Z,1566415490.808 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190821T185605/Courier0010.lzma 2019-08-21T19:24:51.045Z,1566415491.045 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:51.614Z,1566415491.614 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Courier0010.lzma.bak 2019-08-21T19:24:51.614Z,1566415491.614 [DataOverHttps](INFO): SBD MOMSN=11657973 2019-08-21T19:24:53.061Z,1566415493.061 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:55.081Z,1566415495.081 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:24:58.313Z,1566415498.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:01.145Z,1566415501.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:02.541Z,1566415502.541 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20190821T185605/Express0011.lzma 2019-08-21T19:25:03.346Z,1566415503.346 [DataOverHttps](INFO): Moved sent file to Logs/20190821T185605/Express0011.lzma.bak 2019-08-21T19:25:03.346Z,1566415503.346 [DataOverHttps](INFO): SBD MOMSN=11657975 2019-08-21T19:25:03.987Z,1566415503.987 [Default:CheckIn:Read_Iridium] Stopped 2019-08-21T19:25:03.987Z,1566415503.987 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-21T19:25:03.987Z,1566415503.987 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-21T19:25:04.373Z,1566415504.373 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:07.201Z,1566415507.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:10.029Z,1566415510.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:12.105Z,1566415512.105 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:14.069Z,1566415514.069 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:17.301Z,1566415517.301 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:20.129Z,1566415520.129 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:23.361Z,1566415523.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:26.193Z,1566415526.193 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:29.017Z,1566415529.017 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:31.037Z,1566415531.037 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:33.057Z,1566415533.057 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:35.093Z,1566415535.093 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:38.321Z,1566415538.321 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:41.153Z,1566415541.153 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:44.441Z,1566415544.441 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:47.217Z,1566415547.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:50.045Z,1566415550.045 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:52.061Z,1566415552.061 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:54.097Z,1566415554.097 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:25:57.329Z,1566415557.329 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:00.145Z,1566415560.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:03.377Z,1566415563.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:06.201Z,1566415566.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:09.029Z,1566415569.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:11.065Z,1566415571.065 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:13.073Z,1566415573.073 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:16.301Z,1566415576.301 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:19.129Z,1566415579.129 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:22.361Z,1566415582.361 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:25.189Z,1566415585.189 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:26.426Z,1566415586.426 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2019-08-21T19:26:26.426Z,1566415586.426 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:26:26.436Z,1566415586.436 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:26:26.902Z,1566415586.902 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:26:26.902Z,1566415586.902 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2019-08-21T19:26:28.425Z,1566415588.425 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:31.257Z,1566415591.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:34.081Z,1566415594.081 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:37.309Z,1566415597.309 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:40.137Z,1566415600.137 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:43.385Z,1566415603.385 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:46.197Z,1566415606.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:49.429Z,1566415609.429 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:52.269Z,1566415612.269 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:55.089Z,1566415615.089 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:26:58.321Z,1566415618.321 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:01.149Z,1566415621.149 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:04.377Z,1566415624.377 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:07.213Z,1566415627.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:10.033Z,1566415630.033 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:12.069Z,1566415632.069 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:14.089Z,1566415634.089 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:14.874Z,1566415634.874 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:27:14.874Z,1566415634.874 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:27:14.874Z,1566415634.874 [DVL_micro](ERROR): Data Fault 2019-08-21T19:27:14.930Z,1566415634.930 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:27:15.357Z,1566415635.357 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:27:16.136Z,1566415636.136 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:27:16.136Z,1566415636.136 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:27:16.488Z,1566415636.488 [DVL_micro](INFO): Initializing 2019-08-21T19:27:17.305Z,1566415637.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:18.127Z,1566415638.127 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2019-08-21T19:27:18.130Z,1566415638.130 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2019-08-21T19:27:20.133Z,1566415640.133 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:23.365Z,1566415643.365 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:26.221Z,1566415646.221 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:29.437Z,1566415649.437 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:32.257Z,1566415652.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:35.089Z,1566415655.089 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:38.321Z,1566415658.321 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:41.149Z,1566415661.149 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:44.397Z,1566415664.397 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:47.213Z,1566415667.213 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:50.041Z,1566415670.041 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:52.069Z,1566415672.069 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:54.081Z,1566415674.081 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:27:57.309Z,1566415677.309 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:00.141Z,1566415680.141 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:03.369Z,1566415683.369 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:06.197Z,1566415686.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:09.025Z,1566415689.025 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:11.049Z,1566415691.049 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:13.065Z,1566415693.065 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:16.313Z,1566415696.313 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:19.125Z,1566415699.125 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:28:22.347Z,1566415702.347 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-21T19:28:22.347Z,1566415702.347 [NAL9602] Data Fault, FailCount= 3 2019-08-21T19:28:22.347Z,1566415702.347 [NAL9602](ERROR): Data Fault 2019-08-21T19:28:22.383Z,1566415702.383 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-21T19:28:22.747Z,1566415702.747 [NAL9602](INFO): Powering down 2019-08-21T19:28:23.596Z,1566415703.596 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-21T19:28:23.596Z,1566415703.596 [NAL9602] No Fault, FailCount= 3 2019-08-21T19:28:53.051Z,1566415733.051 [NAL9602](INFO): Powering up NAL9602 2019-08-21T19:29:03.959Z,1566415743.959 [NAL9602](INFO): NAL9602 initialized 2019-08-21T19:29:04.785Z,1566415744.785 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:07.201Z,1566415747.201 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:10.029Z,1566415750.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:13.265Z,1566415753.265 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:16.105Z,1566415756.105 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:18.929Z,1566415758.929 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:20.937Z,1566415760.937 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:22.957Z,1566415762.957 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:26.189Z,1566415766.189 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:27.414Z,1566415767.414 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2019-08-21T19:29:27.414Z,1566415767.414 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:29:27.424Z,1566415767.424 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:29:27.830Z,1566415767.830 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:29:27.830Z,1566415767.830 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2019-08-21T19:29:29.045Z,1566415769.045 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:32.277Z,1566415772.277 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:35.081Z,1566415775.081 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:38.309Z,1566415778.309 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:41.137Z,1566415781.137 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:43.965Z,1566415783.965 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:47.205Z,1566415787.205 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:50.029Z,1566415790.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:53.261Z,1566415793.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:56.093Z,1566415796.093 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:29:58.917Z,1566415798.917 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:00.933Z,1566415800.933 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:02.953Z,1566415802.953 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:04.595Z,1566415804.595 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-21T19:30:04.595Z,1566415804.595 [Default:CheckIn:C.Wait] Stopped 2019-08-21T19:30:04.595Z,1566415804.595 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-21T19:30:04.595Z,1566415804.595 [Default:CheckIn:D] Running Loop=1 2019-08-21T19:30:04.987Z,1566415804.987 [Default:CheckIn:D] Stopped 2019-08-21T19:30:04.987Z,1566415804.987 [Default:CheckIn:E] Running Loop=1 2019-08-21T19:30:05.391Z,1566415805.391 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.117328 min 2019-08-21T19:30:05.391Z,1566415805.391 [Default:CheckIn:E] Stopped 2019-08-21T19:30:05.391Z,1566415805.391 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-21T19:30:05.391Z,1566415805.391 [Default:CheckIn] Stopped 2019-08-21T19:30:05.391Z,1566415805.391 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-21T19:30:05.392Z,1566415805.392 [Default:CheckIn](INFO): Running loop #4 2019-08-21T19:30:05.392Z,1566415805.392 [Default:CheckIn] Running Loop=4 2019-08-21T19:30:05.392Z,1566415805.392 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-21T19:30:05.392Z,1566415805.392 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-21T19:30:06.188Z,1566415806.188 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:09.017Z,1566415809.017 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:12.245Z,1566415812.245 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:15.073Z,1566415815.073 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:18.305Z,1566415818.305 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:20.726Z,1566415820.726 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-21T19:30:20.726Z,1566415820.726 [DVL_micro] Data Fault, FailCount= 1 2019-08-21T19:30:20.726Z,1566415820.726 [DVL_micro](ERROR): Data Fault 2019-08-21T19:30:20.790Z,1566415820.790 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-21T19:30:21.193Z,1566415821.193 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:30:21.205Z,1566415821.205 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:21.975Z,1566415821.975 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-21T19:30:21.975Z,1566415821.975 [DVL_micro] No Fault, FailCount= 1 2019-08-21T19:30:22.336Z,1566415822.336 [DVL_micro](INFO): Initializing 2019-08-21T19:30:23.961Z,1566415823.961 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:27.197Z,1566415827.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:30.021Z,1566415830.021 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:33.253Z,1566415833.253 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:36.085Z,1566415836.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:38.909Z,1566415838.909 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:40.925Z,1566415840.925 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:42.949Z,1566415842.949 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:44.985Z,1566415844.985 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:48.217Z,1566415848.217 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:51.032Z,1566415851.032 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:54.261Z,1566415854.261 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:57.089Z,1566415857.089 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:30:59.917Z,1566415859.917 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:01.941Z,1566415861.941 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:03.957Z,1566415863.957 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:07.193Z,1566415867.193 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:10.017Z,1566415870.017 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:13.253Z,1566415873.253 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:16.081Z,1566415876.081 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:19.309Z,1566415879.309 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:22.149Z,1566415882.149 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:24.965Z,1566415884.965 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:28.197Z,1566415888.197 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:31.029Z,1566415891.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:34.257Z,1566415894.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:37.089Z,1566415897.089 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:39.925Z,1566415899.925 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:41.937Z,1566415901.937 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:43.949Z,1566415903.949 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:47.189Z,1566415907.189 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:50.029Z,1566415910.029 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:53.249Z,1566415913.249 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:56.093Z,1566415916.093 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:31:59.325Z,1566415919.325 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:02.145Z,1566415922.145 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:04.961Z,1566415924.961 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:08.193Z,1566415928.193 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:11.021Z,1566415931.021 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:14.257Z,1566415934.257 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:17.085Z,1566415937.085 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:19.921Z,1566415939.921 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:21.993Z,1566415941.993 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:23.949Z,1566415943.949 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:27.181Z,1566415947.181 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:28.474Z,1566415948.474 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2019-08-21T19:32:28.474Z,1566415948.474 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-21T19:32:28.503Z,1566415948.503 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-21T19:32:28.839Z,1566415948.839 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-21T19:32:28.840Z,1566415948.840 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2019-08-21T19:32:30.005Z,1566415950.005 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:31.638Z,1566415951.638 [DVL_micro](ERROR): only read 43 of 46 data items 2019-08-21T19:32:31.639Z,1566415951.639 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X00 0 0 0 0 0 0 0 0 0 406 473 427 431 2 2 2 2 -28.0 56.1 468.3 2 -61.8 10.4 468.3 2 -28 56 468 2 -61 10 468 2 19.49 -1.20 53.9 -3.0 20.4 0.005 35.01 2019-08-21T19:32:33.241Z,1566415953.241 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:36.073Z,1566415956.073 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:38.897Z,1566415958.897 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:40.921Z,1566415960.921 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:42.937Z,1566415962.937 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:43.593Z,1566415963.593 [CommandLine](IMPORTANT): got command restart application 2019-08-21T19:32:44.597Z,1566415964.597 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:44.597Z,1566415964.597 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:44.713Z,1566415964.713 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-08-21T19:32:44.713Z,1566415964.713 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:44.714Z,1566415964.714 [CommandLine](INFO): Join timeout helper Thread ID is 992 2019-08-21T19:32:44.715Z,1566415964.715 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-08-21T19:32:44.715Z,1566415964.715 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:44.716Z,1566415964.716 [NavChartDb](INFO): Join timeout helper Thread ID is 993 2019-08-21T19:32:44.965Z,1566415964.965 [NAL9602](DEBUG): Fix Requested 2019-08-21T19:32:45.105Z,1566415965.105 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:45.105Z,1566415965.105 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:45.125Z,1566415965.125 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-08-21T19:32:45.125Z,1566415965.125 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:45.125Z,1566415965.125 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 994 2019-08-21T19:32:45.481Z,1566415965.481 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:45.481Z,1566415965.481 [WetLabsBB2FL](INFO): Powering down 2019-08-21T19:32:45.482Z,1566415965.482 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:45.493Z,1566415965.493 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-08-21T19:32:45.493Z,1566415965.493 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:45.493Z,1566415965.493 [CTD_Seabird](INFO): Join timeout helper Thread ID is 995 2019-08-21T19:32:46.045Z,1566415966.045 [CTD_Seabird](INFO): Powering down 2019-08-21T19:32:46.057Z,1566415966.057 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:46.057Z,1566415966.057 [CTD_Seabird](INFO): Powering down 2019-08-21T19:32:46.069Z,1566415966.069 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.081Z,1566415966.081 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-08-21T19:32:46.081Z,1566415966.081 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.081Z,1566415966.081 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 996 2019-08-21T19:32:46.253Z,1566415966.253 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:46.253Z,1566415966.253 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.276Z,1566415966.276 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-08-21T19:32:46.276Z,1566415966.276 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.276Z,1566415966.276 [Radio_Surface](INFO): Join timeout helper Thread ID is 997 2019-08-21T19:32:46.329Z,1566415966.329 [Radio_Surface](INFO): Powering down 2019-08-21T19:32:46.330Z,1566415966.330 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:46.330Z,1566415966.330 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.331Z,1566415966.331 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-08-21T19:32:46.332Z,1566415966.332 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.332Z,1566415966.332 [DataOverHttps](INFO): Join timeout helper Thread ID is 998 2019-08-21T19:32:46.401Z,1566415966.401 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:46.405Z,1566415966.405 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.418Z,1566415966.418 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-08-21T19:32:46.418Z,1566415966.418 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.418Z,1566415966.418 [logger](INFO): Join timeout helper Thread ID is 999 2019-08-21T19:32:46.425Z,1566415966.425 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:46.425Z,1566415966.425 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.437Z,1566415966.437 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-08-21T19:32:46.438Z,1566415966.438 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.438Z,1566415966.438 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-08-21T19:32:46.438Z,1566415966.438 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.438Z,1566415966.438 [controlThread](INFO): Join timeout helper Thread ID is 1000 2019-08-21T19:32:46.549Z,1566415966.549 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-21T19:32:46.549Z,1566415966.549 [controlThread](DEBUG): Uninitializing ControlThread 2019-08-21T19:32:46.550Z,1566415966.550 [AHRS_M2](INFO): Powering down 2019-08-21T19:32:46.693Z,1566415966.693 [DVL_micro](INFO): uninitialize:Powering down 2019-08-21T19:32:46.694Z,1566415966.694 [NAL9602](INFO): Powering down 2019-08-21T19:32:46.696Z,1566415966.696 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-08-21T19:32:46.697Z,1566415966.697 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-08-21T19:32:46.697Z,1566415966.697 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-08-21T19:32:46.698Z,1566415966.698 [MissionManager](INFO): Uninitializing Mission Default 2019-08-21T19:32:46.698Z,1566415966.698 [Default] Stopped 2019-08-21T19:32:46.698Z,1566415966.698 [Default](DEBUG): Aggregate::uninitialize Default 2019-08-21T19:32:46.698Z,1566415966.698 [Default:B.GoToSurface] Stopped 2019-08-21T19:32:46.698Z,1566415966.698 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-21T19:32:46.698Z,1566415966.698 [Default:CheckIn] Stopped 2019-08-21T19:32:46.698Z,1566415966.698 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-21T19:32:46.698Z,1566415966.698 [Default:CheckIn:Read_GPS] Stopped 2019-08-21T19:32:46.701Z,1566415966.701 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-08-21T19:32:46.701Z,1566415966.701 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-08-21T19:32:46.701Z,1566415966.701 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-08-21T19:32:46.702Z,1566415966.702 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-08-21T19:32:46.702Z,1566415966.702 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-08-21T19:32:46.702Z,1566415966.702 [BuoyancyServo](INFO): Powering down 2019-08-21T19:32:46.717Z,1566415966.717 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-08-21T19:32:46.717Z,1566415966.717 [ElevatorServo](INFO): Powering down 2019-08-21T19:32:46.718Z,1566415966.718 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-08-21T19:32:46.718Z,1566415966.718 [MassServo](INFO): Powering down 2019-08-21T19:32:46.719Z,1566415966.719 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-21T19:32:46.719Z,1566415966.719 [RudderServo](INFO): Powering down 2019-08-21T19:32:46.720Z,1566415966.720 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-08-21T19:32:46.720Z,1566415966.720 [ThrusterServo](INFO): Powering down 2019-08-21T19:32:46.721Z,1566415966.721 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-08-21T19:32:46.721Z,1566415966.721 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-08-21T19:32:46.721Z,1566415966.721 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-08-21T19:32:46.721Z,1566415966.721 [CBIT](DEBUG): Powering off loads. 2019-08-21T19:32:46.733Z,1566415966.733 [CBIT](DEBUG): Disabling WDT. 2019-08-21T19:32:46.745Z,1566415966.745 [CBIT](DEBUG): Opening all GF detection circuits. 2019-08-21T19:32:46.745Z,1566415966.745 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.826Z,1566415966.826 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.834Z,1566415966.834 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.876Z,1566415966.876 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.878Z,1566415966.878 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.882Z,1566415966.882 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.918Z,1566415966.918 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-21T19:32:46.962Z,1566415966.962 [logger ThreadHandler](INFO): Thread cancelled.