2020-06-09T15:06:38.032Z,1591715198.032 [Supervisor](DEBUG): Initializing supervisor. 2020-06-09T15:06:38.035Z,1591715198.035 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-06-09T15:06:38.035Z,1591715198.035 [SyncHandler](INFO): Protected caller Thread ID is 452 2020-06-09T15:06:38.036Z,1591715198.036 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-06-09T15:06:38.037Z,1591715198.037 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-06-09T15:06:38.037Z,1591715198.037 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 453 2020-06-09T15:06:38.040Z,1591715198.040 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-06-09T15:06:38.053Z,1591715198.053 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-06-09T15:06:38.054Z,1591715198.054 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-06-09T15:06:38.054Z,1591715198.054 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 454 2020-06-09T15:06:38.055Z,1591715198.055 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-06-09T15:06:38.056Z,1591715198.056 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-06-09T15:06:38.056Z,1591715198.056 [logger ThreadHandler](INFO): Protected caller Thread ID is 455 2020-06-09T15:06:38.058Z,1591715198.058 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-06-09T15:06:38.058Z,1591715198.058 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-06-09T15:06:38.060Z,1591715198.060 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-06-09T15:06:38.366Z,1591715198.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-06-09T15:06:38.367Z,1591715198.367 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-06-09T15:06:38.951Z,1591715198.951 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-06-09T15:06:38.951Z,1591715198.951 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-06-09T15:06:39.088Z,1591715199.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-06-09T15:06:39.088Z,1591715199.088 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-06-09T15:06:39.542Z,1591715199.542 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-06-09T15:06:39.542Z,1591715199.542 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-06-09T15:06:39.636Z,1591715199.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-06-09T15:06:39.636Z,1591715199.636 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-06-09T15:06:39.716Z,1591715199.716 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-06-09T15:06:40.015Z,1591715200.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-06-09T15:06:40.015Z,1591715200.015 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-06-09T15:06:40.170Z,1591715200.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-06-09T15:06:40.170Z,1591715200.170 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-06-09T15:06:40.271Z,1591715200.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-06-09T15:06:40.272Z,1591715200.272 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-06-09T15:06:40.468Z,1591715200.468 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-06-09T15:06:40.468Z,1591715200.468 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-06-09T15:06:40.939Z,1591715200.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-06-09T15:06:40.940Z,1591715200.940 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-06-09T15:06:41.352Z,1591715201.352 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-06-09T15:06:41.352Z,1591715201.352 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-06-09T15:06:41.451Z,1591715201.451 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-06-09T15:06:41.452Z,1591715201.452 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-06-09T15:06:41.640Z,1591715201.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-06-09T15:06:41.640Z,1591715201.640 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-06-09T15:06:41.844Z,1591715201.844 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-06-09T15:06:41.845Z,1591715201.845 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-06-09T15:06:42.064Z,1591715202.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-06-09T15:06:42.067Z,1591715202.067 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2020-06-09T15:06:42.067Z,1591715202.067 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2020-06-09T15:06:42.158Z,1591715202.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2020-06-09T15:06:42.294Z,1591715202.294 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2020-06-09T15:06:42.376Z,1591715202.376 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2020-06-09T15:06:42.456Z,1591715202.456 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2020-06-09T15:06:42.559Z,1591715202.559 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2020-06-09T15:06:42.750Z,1591715202.750 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2020-06-09T15:06:43.337Z,1591715203.337 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-06-09T15:06:43.338Z,1591715203.338 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2020-06-09T15:06:43.446Z,1591715203.446 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2020-06-09T15:06:43.538Z,1591715203.538 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2020-06-09T15:06:43.638Z,1591715203.638 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2020-06-09T15:06:43.728Z,1591715203.728 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-06-09T15:06:43.734Z,1591715203.734 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-06-09T15:06:43.809Z,1591715203.809 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-06-09T15:06:43.810Z,1591715203.810 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-06-09T15:06:43.829Z,1591715203.829 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-06-09T15:06:43.830Z,1591715203.830 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-06-09T15:06:43.871Z,1591715203.871 [DepthRateCalculator] Loaded 2020-06-09T15:06:43.871Z,1591715203.871 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-06-09T15:06:43.877Z,1591715203.877 [PitchRateCalculator] Loaded 2020-06-09T15:06:43.877Z,1591715203.877 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-06-09T15:06:43.892Z,1591715203.892 [SpeedCalculator] Loaded 2020-06-09T15:06:43.892Z,1591715203.892 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-06-09T15:06:43.913Z,1591715203.913 [TempGradientCalculator] Loaded 2020-06-09T15:06:43.914Z,1591715203.914 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-06-09T15:06:43.919Z,1591715203.919 [YawRateCalculator] Loaded 2020-06-09T15:06:43.919Z,1591715203.919 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-06-09T15:06:43.958Z,1591715203.958 [ElevatorOffsetCalculator] Loaded 2020-06-09T15:06:43.958Z,1591715203.958 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-06-09T15:06:43.958Z,1591715203.958 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-06-09T15:06:43.959Z,1591715203.959 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-06-09T15:06:44.006Z,1591715204.006 [VerticalControl](DEBUG): Construct VerticalControl. 2020-06-09T15:06:44.102Z,1591715204.102 [VerticalControl] Loaded 2020-06-09T15:06:44.102Z,1591715204.102 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-06-09T15:06:44.102Z,1591715204.102 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-06-09T15:06:44.180Z,1591715204.180 [HorizontalControl] Loaded 2020-06-09T15:06:44.180Z,1591715204.180 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-06-09T15:06:44.181Z,1591715204.181 [SpeedControl](DEBUG): Construct SpeedControl. 2020-06-09T15:06:44.186Z,1591715204.186 [SpeedControl] Loaded 2020-06-09T15:06:44.186Z,1591715204.186 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-06-09T15:06:44.187Z,1591715204.187 [LoopControl](DEBUG): Construct LoopControl. 2020-06-09T15:06:44.187Z,1591715204.187 [LoopControl] Loaded 2020-06-09T15:06:44.187Z,1591715204.187 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-06-09T15:06:44.188Z,1591715204.188 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-06-09T15:06:44.188Z,1591715204.188 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-06-09T15:06:44.303Z,1591715204.303 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-06-09T15:06:44.303Z,1591715204.303 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-06-09T15:06:44.322Z,1591715204.322 [NavChart] Loaded 2020-06-09T15:06:44.323Z,1591715204.323 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-06-09T15:06:44.327Z,1591715204.327 [UniversalFixResidualReporter] Loaded 2020-06-09T15:06:44.327Z,1591715204.327 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-06-09T15:06:44.327Z,1591715204.327 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-06-09T15:06:44.328Z,1591715204.328 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-06-09T15:06:44.428Z,1591715204.428 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-06-09T15:06:44.428Z,1591715204.428 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-06-09T15:06:44.721Z,1591715204.721 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-06-09T15:06:44.726Z,1591715204.726 [AHRS_M2](INFO): created writer for : platform_orientation 2020-06-09T15:06:44.728Z,1591715204.728 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-06-09T15:06:44.733Z,1591715204.733 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-06-09T15:06:44.734Z,1591715204.734 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-06-09T15:06:44.738Z,1591715204.738 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-06-09T15:06:44.739Z,1591715204.739 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-06-09T15:06:44.744Z,1591715204.744 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-06-09T15:06:44.813Z,1591715204.813 [AHRS_M2] Loaded 2020-06-09T15:06:44.813Z,1591715204.813 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-06-09T15:06:44.891Z,1591715204.891 [DataOverHttps] Loaded 2020-06-09T15:06:44.891Z,1591715204.891 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-06-09T15:06:44.892Z,1591715204.892 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408544E0 2020-06-09T15:06:44.892Z,1591715204.892 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 539 2020-06-09T15:06:44.906Z,1591715204.906 [Depth_Keller] Loaded 2020-06-09T15:06:44.906Z,1591715204.906 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-06-09T15:06:44.911Z,1591715204.911 [DropWeight] Loaded 2020-06-09T15:06:44.911Z,1591715204.911 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-06-09T15:06:44.955Z,1591715204.955 [DVL_micro] Loaded 2020-06-09T15:06:44.955Z,1591715204.955 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2020-06-09T15:06:45.048Z,1591715205.048 [NAL9602] Loaded 2020-06-09T15:06:45.048Z,1591715205.048 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-06-09T15:06:45.125Z,1591715205.125 [Onboard] Loaded 2020-06-09T15:06:45.125Z,1591715205.125 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2020-06-09T15:06:45.128Z,1591715205.128 [Radio_Surface] Loaded 2020-06-09T15:06:45.128Z,1591715205.128 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-06-09T15:06:45.129Z,1591715205.129 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0 2020-06-09T15:06:45.130Z,1591715205.130 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 540 2020-06-09T15:06:45.259Z,1591715205.259 [DAT] Loaded 2020-06-09T15:06:45.259Z,1591715205.259 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-06-09T15:06:46.716Z,1591715206.716 [BPC1] Loaded 2020-06-09T15:06:46.716Z,1591715206.716 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-06-09T15:06:46.717Z,1591715206.717 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-06-09T15:06:46.717Z,1591715206.717 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-06-09T15:06:46.820Z,1591715206.820 [BuoyancyServo] Loaded 2020-06-09T15:06:46.820Z,1591715206.820 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-06-09T15:06:46.831Z,1591715206.831 [ElevatorServo] Loaded 2020-06-09T15:06:46.831Z,1591715206.831 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-06-09T15:06:46.842Z,1591715206.842 [MassServo] Loaded 2020-06-09T15:06:46.842Z,1591715206.842 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-06-09T15:06:46.853Z,1591715206.853 [RudderServo] Loaded 2020-06-09T15:06:46.853Z,1591715206.853 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-06-09T15:06:46.863Z,1591715206.863 [ThrusterServo] Loaded 2020-06-09T15:06:46.864Z,1591715206.864 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-06-09T15:06:46.864Z,1591715206.864 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-06-09T15:06:46.864Z,1591715206.864 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-06-09T15:06:46.948Z,1591715206.948 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-06-09T15:06:46.949Z,1591715206.949 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-06-09T15:06:46.976Z,1591715206.976 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-06-09T15:06:46.977Z,1591715206.977 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-06-09T15:06:47.261Z,1591715207.261 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-06-09T15:06:47.261Z,1591715207.261 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-06-09T15:06:47.451Z,1591715207.451 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-06-09T15:06:47.456Z,1591715207.456 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-06-09T15:06:47.457Z,1591715207.457 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-06-09T15:06:47.462Z,1591715207.462 [CTD_Seabird](INFO): created writer for : depth 2020-06-09T15:06:47.462Z,1591715207.462 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-06-09T15:06:47.467Z,1591715207.467 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-06-09T15:06:47.468Z,1591715207.468 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-06-09T15:06:47.473Z,1591715207.473 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-06-09T15:06:47.473Z,1591715207.473 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-06-09T15:06:47.478Z,1591715207.478 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-06-09T15:06:47.479Z,1591715207.479 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-06-09T15:06:47.484Z,1591715207.484 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-06-09T15:06:47.485Z,1591715207.485 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-06-09T15:06:47.490Z,1591715207.490 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-06-09T15:06:47.517Z,1591715207.517 [CTD_Seabird] Loaded 2020-06-09T15:06:47.517Z,1591715207.517 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-06-09T15:06:47.518Z,1591715207.518 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A904E0 2020-06-09T15:06:47.518Z,1591715207.518 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 541 2020-06-09T15:06:47.548Z,1591715207.548 [ESPComponent] Loaded 2020-06-09T15:06:47.548Z,1591715207.548 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2020-06-09T15:06:47.562Z,1591715207.562 [PAR_Licor] Loaded 2020-06-09T15:06:47.562Z,1591715207.562 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2020-06-09T15:06:47.568Z,1591715207.568 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-06-09T15:06:47.568Z,1591715207.568 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-06-09T15:06:47.572Z,1591715207.572 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-06-09T15:06:47.572Z,1591715207.572 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-06-09T15:06:47.576Z,1591715207.576 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-06-09T15:06:47.577Z,1591715207.577 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-06-09T15:06:47.581Z,1591715207.581 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-06-09T15:06:47.581Z,1591715207.581 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-06-09T15:06:47.585Z,1591715207.585 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-06-09T15:06:47.585Z,1591715207.585 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-06-09T15:06:47.589Z,1591715207.589 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-06-09T15:06:47.589Z,1591715207.589 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-06-09T15:06:47.593Z,1591715207.593 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-06-09T15:06:47.593Z,1591715207.593 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-06-09T15:06:47.598Z,1591715207.598 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.602Z,1591715207.602 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.602Z,1591715207.602 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.603Z,1591715207.603 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.607Z,1591715207.607 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.607Z,1591715207.607 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.611Z,1591715207.611 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.611Z,1591715207.611 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T15:06:47.615Z,1591715207.615 [WetLabsBB2FL] Loaded 2020-06-09T15:06:47.616Z,1591715207.616 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-06-09T15:06:47.617Z,1591715207.617 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC04E0 2020-06-09T15:06:47.617Z,1591715207.617 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 542 2020-06-09T15:06:47.618Z,1591715207.618 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-06-09T15:06:47.618Z,1591715207.618 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-06-09T15:06:47.751Z,1591715207.751 [SBIT](DEBUG): Construct Startup Built In Test. 2020-06-09T15:06:47.762Z,1591715207.762 [SBIT] Loaded 2020-06-09T15:06:47.762Z,1591715207.762 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-06-09T15:06:47.763Z,1591715207.763 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-06-09T15:06:47.775Z,1591715207.775 [IBIT] Loaded 2020-06-09T15:06:47.775Z,1591715207.775 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-06-09T15:06:47.778Z,1591715207.778 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-06-09T15:06:47.914Z,1591715207.914 [CBIT] Loaded 2020-06-09T15:06:47.914Z,1591715207.914 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-06-09T15:06:47.914Z,1591715207.914 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-06-09T15:06:47.939Z,1591715207.939 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-06-09T15:06:47.940Z,1591715207.940 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-06-09T15:06:48.081Z,1591715208.081 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-06-09T15:06:48.085Z,1591715208.085 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B2B4E0 2020-06-09T15:06:48.085Z,1591715208.085 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 543 2020-06-09T15:06:48.214Z,1591715208.214 [Supervisor](INFO): Main Thread ID is 451 2020-06-09T15:06:48.214Z,1591715208.214 [Supervisor](DEBUG): Running supervisor. 2020-06-09T15:06:48.214Z,1591715208.214 [CommandLine ThreadHandler](INFO): Handler Thread ID is 544 2020-06-09T15:06:48.217Z,1591715208.217 [controlThread ThreadHandler](INFO): Handler Thread ID is 545 2020-06-09T15:06:48.218Z,1591715208.218 [controlThread](DEBUG): Initializing ControlThread 2020-06-09T15:06:48.219Z,1591715208.219 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-06-09T15:06:48.219Z,1591715208.219 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-06-09T15:06:48.219Z,1591715208.219 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-06-09T15:06:48.220Z,1591715208.220 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-06-09T15:06:48.220Z,1591715208.220 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-06-09T15:06:48.221Z,1591715208.221 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-06-09T15:06:48.221Z,1591715208.221 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-06-09T15:06:48.223Z,1591715208.223 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-06-09T15:06:48.224Z,1591715208.224 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-06-09T15:06:48.224Z,1591715208.224 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-06-09T15:06:48.225Z,1591715208.225 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-06-09T15:06:48.225Z,1591715208.225 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-06-09T15:06:48.237Z,1591715208.237 [SBIT](INFO): Initialize SBIT Component. 2020-06-09T15:06:48.238Z,1591715208.238 [SBIT](IMPORTANT): git: 2020-06-09 2020-06-09T15:06:48.238Z,1591715208.238 [SBIT](INFO): git hash: 492c82351796d8646f9bb5d9c938bbc9efa48549 2020-06-09T15:06:48.238Z,1591715208.238 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-06-09T15:06:48.238Z,1591715208.238 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 2020-06-09T15:06:48.239Z,1591715208.239 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2020-06-09T15:06:48.240Z,1591715208.240 [IBIT](INFO): Initialize IBIT Component. 2020-06-09T15:06:48.241Z,1591715208.241 [CBIT](DEBUG): Initialize CBIT Component. 2020-06-09T15:06:48.242Z,1591715208.242 [logger ThreadHandler](INFO): Handler Thread ID is 546 2020-06-09T15:06:48.253Z,1591715208.253 [CBIT](DEBUG): Initialized mux pins. 2020-06-09T15:06:48.253Z,1591715208.253 [CBIT](DEBUG): Initializing the watchdog timer. 2020-06-09T15:06:48.261Z,1591715208.261 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 547 2020-06-09T15:06:48.262Z,1591715208.262 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-06-09T15:06:48.273Z,1591715208.273 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 548 2020-06-09T15:06:48.277Z,1591715208.277 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-06-09T15:06:48.277Z,1591715208.277 [CBIT](DEBUG): Initializing heartbeat. 2020-06-09T15:06:48.285Z,1591715208.285 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 549 2020-06-09T15:06:48.286Z,1591715208.286 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-06-09T15:06:48.290Z,1591715208.290 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 551 2020-06-09T15:06:48.291Z,1591715208.291 [WetLabsBB2FL](INFO): Powering down 2020-06-09T15:06:48.326Z,1591715208.326 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 552 2020-06-09T15:06:48.330Z,1591715208.330 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-06-09T15:06:48.330Z,1591715208.330 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-06-09T15:06:48.330Z,1591715208.330 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-06-09T15:06:48.330Z,1591715208.330 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-06-09T15:06:48.330Z,1591715208.330 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-06-09T15:06:48.331Z,1591715208.331 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-06-09T15:06:48.331Z,1591715208.331 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-06-09T15:06:48.331Z,1591715208.331 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-06-09T15:06:48.331Z,1591715208.331 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-06-09T15:06:48.331Z,1591715208.331 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-06-09T15:06:48.331Z,1591715208.331 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-06-09T15:06:48.332Z,1591715208.332 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-06-09T15:06:48.332Z,1591715208.332 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-06-09T15:06:48.332Z,1591715208.332 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-06-09T15:06:48.332Z,1591715208.332 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-06-09T15:06:48.332Z,1591715208.332 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-06-09T15:06:48.349Z,1591715208.349 [CBIT](DEBUG): Deactivating GF circuits. 2020-06-09T15:06:48.349Z,1591715208.349 [CBIT](DEBUG): Deactivating emergency mode. 2020-06-09T15:06:48.385Z,1591715208.385 [CBIT](DEBUG): Backplane powered. 2020-06-09T15:06:48.386Z,1591715208.386 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-06-09T15:06:48.396Z,1591715208.396 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-06-09T15:06:48.407Z,1591715208.407 [MissionManager](DEBUG): 2020-06-09T15:06:48.408Z,1591715208.408 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-06-09T15:06:48.482Z,1591715208.482 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-06-09T15:06:48.483Z,1591715208.483 [Default:A.Wait](DEBUG): Construct Wait. 2020-06-09T15:06:48.501Z,1591715208.501 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-06-09T15:06:48.528Z,1591715208.528 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-06-09T15:06:48.530Z,1591715208.530 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-06-09T15:06:48.548Z,1591715208.548 [Default:E.Execute](DEBUG): Construct Execute. 2020-06-09T15:06:48.551Z,1591715208.551 [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 2020-06-09T15:06:48.569Z,1591715208.569 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,ESPComponent,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, 2020-06-09T15:06:48.574Z,1591715208.574 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-06-09T15:06:48.647Z,1591715208.647 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T15:06:48.647Z,1591715208.647 [DAT](INFO): Powering up 2020-06-09T15:06:48.647Z,1591715208.647 [DAT](DEBUG): Initializing DAT. 2020-06-09T15:06:48.677Z,1591715208.677 [Radio_Surface](INFO): Powering up 2020-06-09T15:06:48.713Z,1591715208.713 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T15:06:48.763Z,1591715208.763 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-06-09T15:06:48.773Z,1591715208.773 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-06-09T15:06:48.774Z,1591715208.774 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-06-09T15:06:48.785Z,1591715208.785 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-06-09T15:06:48.786Z,1591715208.786 [MassServo](DEBUG): Initializing EZServoServo. 2020-06-09T15:06:48.797Z,1591715208.797 [MassServo](DEBUG): Initializing MassServo. 2020-06-09T15:06:48.798Z,1591715208.798 [RudderServo](DEBUG): Initializing EZServoServo. 2020-06-09T15:06:48.809Z,1591715208.809 [RudderServo](DEBUG): Initializing RudderServo. 2020-06-09T15:06:48.810Z,1591715208.810 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-06-09T15:06:48.817Z,1591715208.817 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-06-09T15:06:49.002Z,1591715209.002 [Depth_Keller](ERROR): Pressure reading out of range: 1829.799438 decibar 2020-06-09T15:06:49.749Z,1591715209.749 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-06-09T15:06:49.749Z,1591715209.749 [RudderServo](FAULT): Rudder failed to initialize 2020-06-09T15:06:49.749Z,1591715209.749 [RudderServo] Communications Fault, FailCount= 1 2020-06-09T15:06:49.749Z,1591715209.749 [RudderServo](ERROR): Communications Fault 2020-06-09T15:06:49.860Z,1591715209.860 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-06-09T15:06:50.062Z,1591715210.062 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-06-09T15:06:50.062Z,1591715210.062 [RudderServo](INFO): Powering down 2020-06-09T15:06:50.709Z,1591715210.709 [RudderServo](DEBUG): Initializing EZServoServo. 2020-06-09T15:06:50.830Z,1591715210.830 [RudderServo](DEBUG): Initializing RudderServo. 2020-06-09T15:06:50.834Z,1591715210.834 [CBIT](INFO): Clearing failed state for component RudderServo 2020-06-09T15:06:50.834Z,1591715210.834 [RudderServo] No Fault, FailCount= 1 2020-06-09T15:07:01.672Z,1591715221.672 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005448 2020-06-09T15:07:02.819Z,1591715222.819 [DAT](INFO): commRate: 800 2020-06-09T15:07:02.819Z,1591715222.819 [DAT](INFO): commRate: 800 2020-06-09T15:07:03.222Z,1591715223.222 [DAT](INFO): entering command mode 2020-06-09T15:07:03.799Z,1591715223.799 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:04.029Z,1591715224.029 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:04.444Z,1591715224.444 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:04.837Z,1591715224.837 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:05.241Z,1591715225.241 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:05.655Z,1591715225.655 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:06.050Z,1591715226.050 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:06.463Z,1591715226.463 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:06.858Z,1591715226.858 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:07.261Z,1591715227.261 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:07.665Z,1591715227.665 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:08.069Z,1591715228.069 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:08.495Z,1591715228.495 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:08.887Z,1591715228.887 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:09.282Z,1591715229.282 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:09.685Z,1591715229.685 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:10.090Z,1591715230.090 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:10.494Z,1591715230.494 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:10.898Z,1591715230.898 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:11.309Z,1591715231.309 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:11.715Z,1591715231.715 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:12.109Z,1591715232.109 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:12.514Z,1591715232.514 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:12.917Z,1591715232.917 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:13.322Z,1591715233.322 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:13.725Z,1591715233.725 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:14.148Z,1591715234.148 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:14.535Z,1591715234.535 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:14.933Z,1591715234.933 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:15.327Z,1591715235.327 [NAL9602](INFO): Powering up NAL9602 2020-06-09T15:07:15.343Z,1591715235.343 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:15.750Z,1591715235.750 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:16.152Z,1591715236.152 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:16.560Z,1591715236.560 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:16.958Z,1591715236.958 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:17.362Z,1591715237.362 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:17.771Z,1591715237.771 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:18.165Z,1591715238.165 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:18.585Z,1591715238.585 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T15:07:18.585Z,1591715238.585 [DAT](FAULT): failed to enter command mode 2020-06-09T15:07:18.994Z,1591715238.994 [DAT](INFO): entering command mode 2020-06-09T15:07:19.384Z,1591715239.384 [DAT](INFO): setting verbose to 3 2020-06-09T15:07:19.782Z,1591715239.782 [DAT](INFO): set verbose to 3 2020-06-09T15:07:19.782Z,1591715239.782 [DAT](INFO): setting DatVerbose to 27440 2020-06-09T15:07:20.186Z,1591715240.186 [DAT](INFO): set DatVerbose to 27440 2020-06-09T15:07:20.187Z,1591715240.187 [DAT](INFO): setting transmit power to 8 2020-06-09T15:07:20.598Z,1591715240.598 [DAT](INFO): set transmit power to 8 2020-06-09T15:07:20.599Z,1591715240.599 [DAT](INFO): setting local address to 8 2020-06-09T15:07:21.005Z,1591715241.005 [DAT](INFO): set local address to 8 2020-06-09T15:07:26.251Z,1591715246.251 [NAL9602](INFO): NAL9602 initialized 2020-06-09T15:07:31.892Z,1591715251.892 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:07:31.893Z,1591715251.893 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2020-06-09T15:07:47.688Z,1591715267.688 [SBIT](IMPORTANT): Beginning Startup BIT 2020-06-09T15:07:47.716Z,1591715267.716 [CBIT](IMPORTANT): Beginning ground fault scan 2020-06-09T15:07:58.789Z,1591715278.789 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.004440 CHAN A1 (24V): -0.000815 CHAN A2 (12V): -0.000440 CHAN A3 (5V): 0.000746 CHAN B0 (3.3V): 0.000366 CHAN B1 (3.15aV): -0.000058 CHAN B2 (3.15bV): 0.000022 CHAN B3 (GND): 0.000340 OPEN: 0.003807 Full Scale Calc: 4.765 mA, -1.589 mA 2020-06-09T15:08:07.370Z,1591715287.370 [DVL_micro](ERROR): Failed to parse: :WI,-00968,-01225,+00330,+00000,A 2020-06-09T15:08:10.180Z,1591715290.180 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:08:10.181Z,1591715290.181 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+17.9,0000.0,14 2020-06-09T15:08:41.423Z,1591715321.423 [SBIT](IMPORTANT): SBIT PASSED 2020-06-09T15:08:41.423Z,1591715321.423 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-06-09T15:08:41.424Z,1591715321.424 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool; 2020-06-09T15:08:41.424Z,1591715321.424 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool; 2020-06-09T15:08:41.424Z,1591715321.424 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=242.907926 cubic_centimeter; 2020-06-09T15:08:41.424Z,1591715321.424 [SBIT](IMPORTANT): VerticalControl.massDefault=9.890285 millimeter; 2020-06-09T15:08:41.843Z,1591715321.843 [MissionManager](IMPORTANT): Started mission Startup 2020-06-09T15:08:41.843Z,1591715321.843 [Startup] Running Loop=1 2020-06-09T15:08:41.843Z,1591715321.843 [Startup](DEBUG): Aggregate::initialize Startup 2020-06-09T15:08:41.843Z,1591715321.843 [Startup:A.GoToSurface] Running Loop=1 2020-06-09T15:08:41.844Z,1591715321.844 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-06-09T15:08:41.844Z,1591715321.844 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-06-09T15:08:41.864Z,1591715321.864 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-06-09T15:08:41.866Z,1591715321.866 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-06-09T15:08:41.866Z,1591715321.866 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-06-09T15:08:41.866Z,1591715321.866 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-06-09T15:08:41.868Z,1591715321.868 [Startup:StartupSatComms] Running Loop=1 2020-06-09T15:08:41.868Z,1591715321.868 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-06-09T15:08:41.868Z,1591715321.868 [Startup:StartupSatComms:A] Running Loop=1 2020-06-09T15:08:42.247Z,1591715322.247 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-06-09T15:08:48.271Z,1591715328.271 [DVL_micro](ERROR): Failed to parse: 00000000017.9,0000.0,1489.0,000 2020-06-09T15:09:11.297Z,1591715351.297 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:09:11.297Z,1591715351.297 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+17.9,0000.0000 2020-06-09T15:09:21.017Z,1591715361.017 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2020-06-09T15:09:39.176Z,1591715379.176 [DVL_micro](ERROR): Failed to parse: :WI,-00699,-01560,+00387,+000I,-00699,-0157,+00000,I 2020-06-09T15:09:42.026Z,1591715382.026 [Startup:StartupSatComms:A](INFO): Timed out from 2020-06-09T15:08:41.9Z 2020-06-09T15:09:42.026Z,1591715382.026 [Startup:StartupSatComms:A] Stopped 2020-06-09T15:09:42.026Z,1591715382.026 [Startup:StartupSatComms:B] Running Loop=1 2020-06-09T15:09:42.430Z,1591715382.430 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-06-09T15:09:48.577Z,1591715388.577 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-06-09T15:09:48.578Z,1591715388.578 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:09:48.596Z,1591715388.596 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:09:49.022Z,1591715389.022 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:09:49.022Z,1591715389.022 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-06-09T15:09:50.936Z,1591715390.936 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T041304/Courier0004.lzma 2020-06-09T15:09:51.939Z,1591715391.939 [DataOverHttps](INFO): Moved sent file to Logs/20200609T041304/Courier0004.lzma.bak 2020-06-09T15:09:51.939Z,1591715391.939 [DataOverHttps](INFO): SBD MOMSN=12374252 2020-06-09T15:10:11.701Z,1591715411.701 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200609T150638/Courier0000.lzma 2020-06-09T15:10:12.376Z,1591715412.376 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:10:12.377Z,1591715412.377 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+17.9,0000.0,00 2020-06-09T15:10:12.703Z,1591715412.703 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0000.lzma.bak 2020-06-09T15:10:12.703Z,1591715412.703 [DataOverHttps](INFO): SBD MOMSN=12374254 2020-06-09T15:10:32.146Z,1591715432.146 [DataOverHttps](INFO): Sending 353 bytes from file Logs/20200609T041304/Express0005.lzma 2020-06-09T15:10:33.147Z,1591715433.147 [DataOverHttps](INFO): Moved sent file to Logs/20200609T041304/Express0005.lzma.bak 2020-06-09T15:10:33.147Z,1591715433.147 [DataOverHttps](INFO): SBD MOMSN=12374257 2020-06-09T15:10:40.252Z,1591715440.252 [DVL_micro](ERROR): Failed to parse: :BI,-01231,-01330,+00362,+00000,I 2020-06-09T15:10:42.334Z,1591715442.334 [Startup:StartupSatComms:B](INFO): Timed out from 2020-06-09T15:09:42.0Z 2020-06-09T15:10:42.334Z,1591715442.334 [Startup:StartupSatComms:B] Stopped 2020-06-09T15:10:42.334Z,1591715442.334 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-06-09T15:10:42.334Z,1591715442.334 [Startup:StartupSatComms] Stopped 2020-06-09T15:10:42.334Z,1591715442.334 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-06-09T15:10:42.335Z,1591715442.335 [Startup](INFO): Completed Startup 2020-06-09T15:10:42.335Z,1591715442.335 [MissionManager](INFO): Startup is completed. 2020-06-09T15:10:42.335Z,1591715442.335 [MissionManager](INFO): Uninitializing Mission Startup 2020-06-09T15:10:42.335Z,1591715442.335 [Startup] Stopped 2020-06-09T15:10:42.335Z,1591715442.335 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-06-09T15:10:42.335Z,1591715442.335 [Startup:A.GoToSurface] Stopped 2020-06-09T15:10:42.335Z,1591715442.335 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-06-09T15:10:42.747Z,1591715442.747 [MissionManager](IMPORTANT): Started mission Default 2020-06-09T15:10:42.747Z,1591715442.747 [Default] Running Loop=1 2020-06-09T15:10:42.747Z,1591715442.747 [Default](DEBUG): Aggregate::initialize Default 2020-06-09T15:10:42.747Z,1591715442.747 [Default:B.GoToSurface] Running Loop=1 2020-06-09T15:10:42.747Z,1591715442.747 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-06-09T15:10:42.748Z,1591715442.748 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-06-09T15:10:42.748Z,1591715442.748 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-06-09T15:10:42.748Z,1591715442.748 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-06-09T15:10:42.748Z,1591715442.748 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-06-09T15:10:42.753Z,1591715442.753 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-06-09T15:10:42.753Z,1591715442.753 [Default:A.Wait] Running Loop=1 2020-06-09T15:10:42.753Z,1591715442.753 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-06-09T15:10:52.559Z,1591715452.559 [DataOverHttps](INFO): Sending 859 bytes from file Logs/20200609T150638/Express0001.lzma 2020-06-09T15:10:53.558Z,1591715453.558 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0001.lzma.bak 2020-06-09T15:10:53.559Z,1591715453.559 [DataOverHttps](INFO): SBD MOMSN=12374274 2020-06-09T15:10:56.075Z,1591715456.075 [Default:A.Wait](INFO): Done Waiting. 2020-06-09T15:10:56.075Z,1591715456.075 [Default:A.Wait] Stopped 2020-06-09T15:10:56.075Z,1591715456.075 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T15:10:56.462Z,1591715456.462 [Default:CheckIn] Running Loop=1 2020-06-09T15:10:56.462Z,1591715456.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T15:10:56.462Z,1591715456.462 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T15:10:56.874Z,1591715456.874 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-06-09T15:11:03.325Z,1591715463.325 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:11:03.325Z,1591715463.325 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2020-06-09T15:12:19.672Z,1591715539.672 [DVL_micro](ERROR): only read 0 of 4 data items 2020-06-09T15:12:19.682Z,1591715539.682 [DVL_micro](ERROR): Failed to parse: :RD,,+9999.99,+99999.99 2020-06-09T15:12:29.367Z,1591715549.367 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-06-09T15:12:50.016Z,1591715570.016 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-06-09T15:12:50.021Z,1591715570.021 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:12:50.043Z,1591715570.043 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:12:50.436Z,1591715570.436 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:12:50.436Z,1591715570.436 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-06-09T15:13:10.573Z,1591715590.573 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:13:10.573Z,1591715590.573 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2020-06-09T15:13:36.027Z,1591715616.027 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:13:36.027Z,1591715616.027 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.0,000.0,000 2020-06-09T15:14:01.477Z,1591715641.477 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: -1257 2020-06-09T15:14:01.480Z,1591715641.480 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2020-06-09T15:14:26.983Z,1591715666.983 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2020-06-09T15:14:26.984Z,1591715666.984 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2020-06-09T15:14:26.991Z,1591715666.991 [BPC1](INFO): Received data from all battery sticks. 2020-06-09T15:15:51.008Z,1591715751.008 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-06-09T15:15:51.008Z,1591715751.008 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:15:51.018Z,1591715751.018 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:15:51.411Z,1591715751.411 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:15:51.411Z,1591715751.411 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-06-09T15:15:56.638Z,1591715756.638 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T15:10:56.5Z 2020-06-09T15:15:56.638Z,1591715756.638 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T15:15:56.638Z,1591715756.638 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T15:15:57.046Z,1591715757.046 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-06-09T15:16:06.177Z,1591715766.177 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20200609T150638/Courier0004.lzma 2020-06-09T15:16:07.178Z,1591715767.178 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0004.lzma.bak 2020-06-09T15:16:07.179Z,1591715767.179 [DataOverHttps](INFO): SBD MOMSN=12374293 2020-06-09T15:16:26.517Z,1591715786.517 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20200609T150638/Express0005.lzma 2020-06-09T15:16:27.519Z,1591715787.519 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0005.lzma.bak 2020-06-09T15:16:27.519Z,1591715787.519 [DataOverHttps](INFO): SBD MOMSN=12374295 2020-06-09T15:16:33.006Z,1591715793.006 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T15:16:33.006Z,1591715793.006 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T15:16:33.006Z,1591715793.006 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T15:16:49.544Z,1591715809.544 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:16:49.545Z,1591715809.545 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.1,0000.0,10 2020-06-09T15:17:12.955Z,1591715832.955 [CommandLine](IMPORTANT): got command failComponent 2020-06-09T15:17:12.955Z,1591715832.955 [CommandLine](IMPORTANT): Failed components: 2020-06-09T15:17:12.955Z,1591715832.955 [CommandLine](IMPORTANT): No failed Components. 2020-06-09T15:17:29.539Z,1591715849.539 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T15:17:29.539Z,1591715849.539 [NAL9602] Data Fault, FailCount= 1 2020-06-09T15:17:29.539Z,1591715849.539 [NAL9602](ERROR): Data Fault 2020-06-09T15:17:29.586Z,1591715849.586 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T15:17:29.954Z,1591715849.954 [NAL9602](INFO): Powering down 2020-06-09T15:17:30.790Z,1591715850.790 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T15:17:30.790Z,1591715850.790 [NAL9602] No Fault, FailCount= 1 2020-06-09T15:17:48.120Z,1591715868.120 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:17:48.120Z,1591715868.120 [DVL_micro](ERROR): Failed to parse: :TS0000000,.2,0000.0000 2020-06-09T15:18:00.243Z,1591715880.243 [NAL9602](INFO): Powering up NAL9602 2020-06-09T15:18:11.155Z,1591715891.155 [NAL9602](INFO): NAL9602 initialized 2020-06-09T15:18:15.999Z,1591715895.999 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:18:15.999Z,1591715895.999 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.2,0000.0,1489.0I,+00244,+0001,+00000,A 2020-06-09T15:18:39.033Z,1591715919.033 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:18:39.033Z,1591715919.033 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2020-06-09T15:18:51.994Z,1591715931.994 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-06-09T15:18:51.994Z,1591715931.994 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:18:52.022Z,1591715932.022 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:18:52.400Z,1591715932.400 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:18:52.401Z,1591715932.401 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-06-09T15:19:21.122Z,1591715961.122 [CommandLine](IMPORTANT): got command show variable abort 2020-06-09T15:19:21.216Z,1591715961.216 [CommandLine](IMPORTANT): CBIT.abortDepth (meter) 2020-06-09T15:19:21.216Z,1591715961.216 [CommandLine](IMPORTANT): CBIT.abortDepthTimeout (second) 2020-06-09T15:19:24.830Z,1591715964.830 [CommandLine](IMPORTANT): got command get CBIT.abortDepth 2020-06-09T15:19:24.831Z,1591715964.831 [CommandLine](IMPORTANT): CBIT.abortDepth 50.000000 m 2020-06-09T15:19:30.847Z,1591715970.847 [CommandLine](IMPORTANT): got command get CBIT.stopDepth 2020-06-09T15:19:30.847Z,1591715970.847 [CommandLine](IMPORTANT): CBIT.stopDepth 40.000000 m 2020-06-09T15:20:20.831Z,1591716020.831 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+9999.99 2020-06-09T15:20:58.859Z,1591716058.859 [CommandLine](IMPORTANT): got command show variable neutral 2020-06-09T15:20:58.868Z,1591716058.868 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter) 2020-06-09T15:20:58.950Z,1591716058.950 [CommandLine](IMPORTANT): Config/Simulator.buoyancyNeutralOffset (cubic_centimeter) 2020-06-09T15:21:08.816Z,1591716068.816 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral 2020-06-09T15:21:08.817Z,1591716068.817 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 242.907928 cc 2020-06-09T15:21:27.315Z,1591716087.315 [CommandLine](IMPORTANT): got command show variable massDefault 2020-06-09T15:21:27.324Z,1591716087.324 [CommandLine](IMPORTANT): VerticalControl.massDefault (centimeter) 2020-06-09T15:21:33.573Z,1591716093.573 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T15:21:33.573Z,1591716093.573 [Default:CheckIn:C.Wait] Stopped 2020-06-09T15:21:33.574Z,1591716093.574 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T15:21:33.574Z,1591716093.574 [Default:CheckIn:D] Running Loop=1 2020-06-09T15:21:33.981Z,1591716093.981 [Default:CheckIn:D] Stopped 2020-06-09T15:21:33.981Z,1591716093.981 [Default:CheckIn:E] Running Loop=1 2020-06-09T15:21:34.407Z,1591716094.407 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.853899 min 2020-06-09T15:21:34.407Z,1591716094.407 [Default:CheckIn:E] Stopped 2020-06-09T15:21:34.407Z,1591716094.407 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T15:21:34.407Z,1591716094.407 [Default:CheckIn] Stopped 2020-06-09T15:21:34.407Z,1591716094.407 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T15:21:34.408Z,1591716094.408 [Default:CheckIn](INFO): Running loop #2 2020-06-09T15:21:34.408Z,1591716094.408 [Default:CheckIn] Running Loop=2 2020-06-09T15:21:34.408Z,1591716094.408 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T15:21:34.408Z,1591716094.408 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T15:21:35.987Z,1591716095.987 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault 2020-06-09T15:21:35.987Z,1591716095.987 [CommandLine](IMPORTANT): VerticalControl.massDefault 0.989028 cm 2020-06-09T15:21:37.190Z,1591716097.190 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:21:37.190Z,1591716097.190 [DVL_micro](ERROR): Failed to parse: :BI,+0978,+00708,+00000,I 2020-06-09T15:21:52.973Z,1591716112.973 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-06-09T15:21:52.973Z,1591716112.973 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:21:52.983Z,1591716112.983 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:21:53.406Z,1591716113.406 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:21:53.407Z,1591716113.407 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-06-09T15:22:50.718Z,1591716170.718 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:22:50.719Z,1591716170.719 [DVL_micro](ERROR): Failed to parse: :BI,-00604,-01194,+00410I 2020-06-09T15:22:55.973Z,1591716175.973 [DVL_micro](ERROR): Failed to parse: :5,-01426,+00471,+00000,I 2020-06-09T15:22:58.390Z,1591716178.390 [DVL_micro](ERROR): No DVL communication! Re-initializing 2020-06-09T15:22:58.390Z,1591716178.390 [DVL_micro] Communications Fault, FailCount= 1 2020-06-09T15:22:58.390Z,1591716178.390 [DVL_micro](ERROR): Communications Fault 2020-06-09T15:22:58.496Z,1591716178.496 [CBIT](ERROR): Communications Fault in component: DVL_micro 2020-06-09T15:22:58.865Z,1591716178.865 [DVL_micro](INFO): Powering down 2020-06-09T15:22:59.672Z,1591716179.672 [CBIT](INFO): Clearing failed state for component DVL_micro 2020-06-09T15:22:59.672Z,1591716179.672 [DVL_micro] No Fault, FailCount= 1 2020-06-09T15:23:25.461Z,1591716205.461 [DVL_micro](ERROR): Failed to parse: :WI,+00830,-01143,+00742,+00000,A 2020-06-09T15:23:50.914Z,1591716230.914 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:23:50.914Z,1591716230.914 [DVL_micro](ERROR): Failed to parse: :BI,+00301,-01370,+0000,I 2020-06-09T15:24:16.373Z,1591716256.373 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:24:16.373Z,1591716256.373 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,14 2020-06-09T15:24:53.966Z,1591716293.966 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-06-09T15:24:53.966Z,1591716293.966 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:24:53.976Z,1591716293.976 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:24:54.416Z,1591716294.416 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:24:54.416Z,1591716294.416 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-06-09T15:25:32.729Z,1591716332.729 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:25:32.729Z,1591716332.729 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2020-06-09T15:25:50.500Z,1591716350.500 [DVL_micro](ERROR): Failed to parse: 0000000000,35.0,+18.5,0000.0,1489.0,000 2020-06-09T15:26:34.559Z,1591716394.559 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T15:21:34.4Z 2020-06-09T15:26:34.559Z,1591716394.559 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T15:26:34.559Z,1591716394.559 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T15:26:43.360Z,1591716403.360 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T150638/Courier0007.lzma 2020-06-09T15:26:44.363Z,1591716404.363 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0007.lzma.bak 2020-06-09T15:26:44.363Z,1591716404.363 [DataOverHttps](INFO): SBD MOMSN=12374299 2020-06-09T15:26:49.077Z,1591716409.077 [DVL_micro](ERROR): Failed to parse: :6,-01141+00000,I 2020-06-09T15:27:03.886Z,1591716423.886 [DataOverHttps](INFO): Sending 498 bytes from file Logs/20200609T150638/Express0008.lzma 2020-06-09T15:27:04.895Z,1591716424.895 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0008.lzma.bak 2020-06-09T15:27:04.895Z,1591716424.895 [DataOverHttps](INFO): SBD MOMSN=12374301 2020-06-09T15:27:09.276Z,1591716429.276 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+18.5,0000.0,1489.0,000 2020-06-09T15:27:09.738Z,1591716429.738 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T15:27:09.738Z,1591716429.738 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T15:27:09.738Z,1591716429.738 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T15:27:39.985Z,1591716459.985 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:27:39.985Z,1591716459.985 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2020-06-09T15:27:54.982Z,1591716474.982 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-06-09T15:27:54.982Z,1591716474.982 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:27:55.020Z,1591716475.020 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:27:55.374Z,1591716475.374 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:27:55.374Z,1591716475.374 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2020-06-09T15:28:05.435Z,1591716485.435 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:28:05.435Z,1591716485.435 [DVL_micro](ERROR): Failed to parse: :BI,-00427,-00974,+0090,I 2020-06-09T15:28:13.511Z,1591716493.511 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T15:28:13.511Z,1591716493.511 [NAL9602] Data Fault, FailCount= 2 2020-06-09T15:28:13.511Z,1591716493.511 [NAL9602](ERROR): Data Fault 2020-06-09T15:28:13.544Z,1591716493.544 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T15:28:13.915Z,1591716493.915 [NAL9602](INFO): Powering down 2020-06-09T15:28:14.761Z,1591716494.761 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T15:28:14.761Z,1591716494.761 [NAL9602] No Fault, FailCount= 2 2020-06-09T15:28:30.884Z,1591716510.884 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:28:30.885Z,1591716510.885 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35,0000.0,1489.0,000 2020-06-09T15:28:44.215Z,1591716524.215 [NAL9602](INFO): Powering up NAL9602 2020-06-09T15:28:55.131Z,1591716535.131 [NAL9602](INFO): NAL9602 initialized 2020-06-09T15:29:21.793Z,1591716561.793 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+18.6,0000.0,1489.0,000 2020-06-09T15:30:12.692Z,1591716612.692 [DVL_micro](ERROR): Failed to parse: 00000000+18.6,0000.0,1489.0,000 2020-06-09T15:30:55.989Z,1591716655.989 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2020-06-09T15:30:55.989Z,1591716655.989 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:30:56.015Z,1591716656.015 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:30:56.386Z,1591716656.386 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:30:56.386Z,1591716656.386 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2020-06-09T15:31:29.049Z,1591716689.049 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:31:29.049Z,1591716689.049 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+1.0,1489.WI,-01320,-01426,+00499,+00000,A 2020-06-09T15:32:10.303Z,1591716730.303 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T15:32:10.303Z,1591716730.303 [Default:CheckIn:C.Wait] Stopped 2020-06-09T15:32:10.303Z,1591716730.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T15:32:10.303Z,1591716730.303 [Default:CheckIn:D] Running Loop=1 2020-06-09T15:32:10.704Z,1591716730.704 [Default:CheckIn:D] Stopped 2020-06-09T15:32:10.704Z,1591716730.704 [Default:CheckIn:E] Running Loop=1 2020-06-09T15:32:11.118Z,1591716731.118 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.465948 min 2020-06-09T15:32:11.118Z,1591716731.118 [Default:CheckIn:E] Stopped 2020-06-09T15:32:11.118Z,1591716731.118 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T15:32:11.118Z,1591716731.118 [Default:CheckIn] Stopped 2020-06-09T15:32:11.118Z,1591716731.118 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T15:32:11.119Z,1591716731.119 [Default:CheckIn](INFO): Running loop #3 2020-06-09T15:32:11.119Z,1591716731.119 [Default:CheckIn] Running Loop=3 2020-06-09T15:32:11.119Z,1591716731.119 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T15:32:11.119Z,1591716731.119 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T15:32:19.956Z,1591716739.956 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:32:19.956Z,1591716739.956 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2020-06-09T15:33:56.950Z,1591716836.950 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2020-06-09T15:33:56.950Z,1591716836.950 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:33:56.960Z,1591716836.960 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:33:57.354Z,1591716837.354 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:33:57.354Z,1591716837.354 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2020-06-09T15:34:19.543Z,1591716859.543 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:34:19.543Z,1591716859.543 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.7,0000.0,1489.0I,+0055,+00799,+00000,A 2020-06-09T15:36:19.120Z,1591716979.120 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:36:19.120Z,1591716979.120 [DVL_micro](ERROR): Failed to parse: :TS,000000000000+18.8,000.0,000 2020-06-09T15:36:57.932Z,1591717017.932 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2020-06-09T15:36:57.932Z,1591717017.932 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:36:57.942Z,1591717017.942 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:36:58.355Z,1591717018.355 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:36:58.355Z,1591717018.355 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2020-06-09T15:37:11.275Z,1591717031.275 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T15:32:11.1Z 2020-06-09T15:37:11.275Z,1591717031.275 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T15:37:11.275Z,1591717031.275 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T15:37:20.216Z,1591717040.216 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T150638/Courier0010.lzma 2020-06-09T15:37:21.219Z,1591717041.219 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0010.lzma.bak 2020-06-09T15:37:21.219Z,1591717041.219 [DataOverHttps](INFO): SBD MOMSN=12374324 2020-06-09T15:37:27.799Z,1591717047.799 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:37:27.799Z,1591717047.799 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.8,0000.0,1489.0I,+00687,-01114,+00798,+00000,A 2020-06-09T15:37:41.149Z,1591717061.149 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200609T150638/Express0011.lzma 2020-06-09T15:37:42.151Z,1591717062.151 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0011.lzma.bak 2020-06-09T15:37:42.151Z,1591717062.151 [DataOverHttps](INFO): SBD MOMSN=12374326 2020-06-09T15:37:46.818Z,1591717066.818 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T15:37:46.818Z,1591717066.818 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T15:37:46.818Z,1591717066.818 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T15:37:55.687Z,1591717075.687 [DVL_micro](ERROR): only read 2 of 4 data items 2020-06-09T15:37:55.687Z,1591717075.687 [DVL_micro](ERROR): Failed to parse: :BI,+00746,-00581+00000,I 2020-06-09T15:38:13.467Z,1591717093.467 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2020-06-09T15:38:57.491Z,1591717137.491 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T15:38:57.491Z,1591717137.491 [NAL9602] Data Fault, FailCount= 3 2020-06-09T15:38:57.491Z,1591717137.491 [NAL9602](ERROR): Data Fault 2020-06-09T15:38:57.542Z,1591717137.542 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T15:38:57.896Z,1591717137.896 [NAL9602](INFO): Powering down 2020-06-09T15:38:58.741Z,1591717138.741 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T15:38:58.741Z,1591717138.741 [NAL9602] No Fault, FailCount= 3 2020-06-09T15:39:28.191Z,1591717168.191 [NAL9602](INFO): Powering up NAL9602 2020-06-09T15:39:39.099Z,1591717179.099 [NAL9602](INFO): NAL9602 initialized 2020-06-09T15:39:58.923Z,1591717198.923 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2020-06-09T15:39:58.923Z,1591717198.923 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:39:58.933Z,1591717198.933 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:39:59.345Z,1591717199.345 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:39:59.345Z,1591717199.345 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2020-06-09T15:40:36.070Z,1591717236.070 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:40:36.070Z,1591717236.070 [DVL_micro](ERROR): Failed to parse: :BI,+0473,+00904,+00000,I 2020-06-09T15:41:01.528Z,1591717261.528 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:41:01.528Z,1591717261.528 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2020-06-09T15:42:28.008Z,1591717348.008 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999..99 2020-06-09T15:42:47.421Z,1591717367.421 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T15:42:47.421Z,1591717367.421 [Default:CheckIn:C.Wait] Stopped 2020-06-09T15:42:47.421Z,1591717367.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T15:42:47.421Z,1591717367.421 [Default:CheckIn:D] Running Loop=1 2020-06-09T15:42:47.827Z,1591717367.827 [Default:CheckIn:D] Stopped 2020-06-09T15:42:47.827Z,1591717367.827 [Default:CheckIn:E] Running Loop=1 2020-06-09T15:42:48.252Z,1591717368.252 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.084658 min 2020-06-09T15:42:48.252Z,1591717368.252 [Default:CheckIn:E] Stopped 2020-06-09T15:42:48.252Z,1591717368.252 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T15:42:48.252Z,1591717368.252 [Default:CheckIn] Stopped 2020-06-09T15:42:48.252Z,1591717368.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T15:42:48.252Z,1591717368.252 [Default:CheckIn](INFO): Running loop #4 2020-06-09T15:42:48.253Z,1591717368.253 [Default:CheckIn] Running Loop=4 2020-06-09T15:42:48.253Z,1591717368.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T15:42:48.253Z,1591717368.253 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T15:42:55.890Z,1591717375.890 [DVL_micro](ERROR): Failed to parse: :SA,-00.94,-06.66,253.9 2020-06-09T15:42:59.962Z,1591717379.962 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2020-06-09T15:42:59.962Z,1591717379.962 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:42:59.972Z,1591717379.972 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:43:00.371Z,1591717380.371 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:43:00.371Z,1591717380.371 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2020-06-09T15:43:44.353Z,1591717424.353 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:43:44.353Z,1591717424.353 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.1,0000.0,1489:WI,+0091,+00809, 2020-06-09T15:44:27.584Z,1591717467.584 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:44:27.584Z,1591717467.584 [DVL_micro](ERROR): Failed to parse: :TS,000000000000009.1,00000,000 2020-06-09T15:44:53.049Z,1591717493.049 [DVL_micro](ERROR): Failed to parse: :WI,+01679,-01035,+00669,+00000,A 2020-06-09T15:46:00.964Z,1591717560.964 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2020-06-09T15:46:00.964Z,1591717560.964 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:46:00.974Z,1591717560.974 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:46:01.403Z,1591717561.403 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:46:01.403Z,1591717561.403 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2020-06-09T15:47:35.879Z,1591717655.879 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:47:35.879Z,1591717655.879 [DVL_micro](ERROR): Failed to parse: :BI,+0401,+00951,+00000,I 2020-06-09T15:47:48.471Z,1591717668.471 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T15:42:48.3Z 2020-06-09T15:47:48.471Z,1591717668.471 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T15:47:48.471Z,1591717668.471 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T15:48:00.172Z,1591717680.172 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T150638/Courier0013.lzma 2020-06-09T15:48:01.175Z,1591717681.175 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0013.lzma.bak 2020-06-09T15:48:01.175Z,1591717681.175 [DataOverHttps](INFO): SBD MOMSN=12374330 2020-06-09T15:48:01.330Z,1591717681.330 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:48:01.330Z,1591717681.330 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.2,0000.0,1489.0,,+00332,-0888,+000I,+00332,-01191,+00888,+00000,I 2020-06-09T15:48:20.297Z,1591717700.297 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200609T150638/Express0014.lzma 2020-06-09T15:48:21.303Z,1591717701.303 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0014.lzma.bak 2020-06-09T15:48:21.304Z,1591717701.304 [DataOverHttps](INFO): SBD MOMSN=12374332 2020-06-09T15:48:26.022Z,1591717706.022 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T15:48:26.022Z,1591717706.022 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T15:48:26.022Z,1591717706.022 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T15:48:26.783Z,1591717706.783 [DVL_micro](ERROR): only read 0 of 4 data items 2020-06-09T15:48:26.783Z,1591717706.783 [DVL_micro](ERROR): Failed to parse: :BI-00257,+00644,+00000,I 2020-06-09T15:48:44.560Z,1591717724.560 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:48:44.560Z,1591717724.560 [DVL_micro](ERROR): Failed to parse: :TS,000000005.0,+19.2,0000.0,1489.0,000 2020-06-09T15:49:01.977Z,1591717741.977 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2020-06-09T15:49:01.977Z,1591717741.977 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:49:02.012Z,1591717742.012 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:49:02.392Z,1591717742.392 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:49:02.392Z,1591717742.392 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2020-06-09T15:49:10.013Z,1591717750.013 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:49:10.013Z,1591717750.013 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+19.2,0000.,000 2020-06-09T15:49:35.461Z,1591717775.461 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:49:35.461Z,1591717775.461 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+190,1489.0I,+00040,-01089,+00996,+00000,A 2020-06-09T15:49:41.115Z,1591717781.115 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T15:49:41.115Z,1591717781.115 [NAL9602] Data Fault, FailCount= 4 2020-06-09T15:49:41.115Z,1591717781.115 [NAL9602](ERROR): Data Fault 2020-06-09T15:49:41.166Z,1591717781.166 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T15:49:41.524Z,1591717781.524 [NAL9602](INFO): Powering down 2020-06-09T15:49:42.369Z,1591717782.369 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T15:49:42.369Z,1591717782.369 [NAL9602] No Fault, FailCount= 4 2020-06-09T15:50:03.351Z,1591717803.351 [DVL_micro](ERROR): Failed to parse: :SA,-00.92,-06.62,253.8 2020-06-09T15:50:11.823Z,1591717811.823 [NAL9602](INFO): Powering up NAL9602 2020-06-09T15:50:22.735Z,1591717822.735 [NAL9602](INFO): NAL9602 initialized 2020-06-09T15:50:44.148Z,1591717844.148 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:50:44.148Z,1591717844.148 [DVL_micro](ERROR): Failed to parse: :BI,+00185,00864,+000D,+00000000.00,+00000000.00,+00000000.00,900.00 2020-06-09T15:52:02.979Z,1591717922.979 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2020-06-09T15:52:02.979Z,1591717922.979 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:52:02.989Z,1591717922.989 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:52:03.383Z,1591717923.383 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:52:03.383Z,1591717923.383 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2020-06-09T15:53:01.509Z,1591717981.509 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T15:53:01.510Z,1591717981.510 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2020-06-09T15:53:26.638Z,1591718006.638 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T15:53:26.638Z,1591718006.638 [Default:CheckIn:C.Wait] Stopped 2020-06-09T15:53:26.638Z,1591718006.638 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T15:53:26.638Z,1591718006.638 [Default:CheckIn:D] Running Loop=1 2020-06-09T15:53:26.987Z,1591718006.987 [Default:CheckIn:D] Stopped 2020-06-09T15:53:26.987Z,1591718006.987 [Default:CheckIn:E] Running Loop=1 2020-06-09T15:53:27.378Z,1591718007.378 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.737329 min 2020-06-09T15:53:27.378Z,1591718007.378 [Default:CheckIn:E] Stopped 2020-06-09T15:53:27.378Z,1591718007.378 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T15:53:27.378Z,1591718007.378 [Default:CheckIn] Stopped 2020-06-09T15:53:27.378Z,1591718007.378 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T15:53:27.378Z,1591718007.378 [Default:CheckIn](INFO): Running loop #5 2020-06-09T15:53:27.379Z,1591718007.379 [Default:CheckIn] Running Loop=5 2020-06-09T15:53:27.379Z,1591718007.379 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T15:53:27.379Z,1591718007.379 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T15:53:44.730Z,1591718024.730 [DVL_micro](ERROR): Failed to parse: :BI,+00312,-01050,+00899,+00000,I 2020-06-09T15:54:10.177Z,1591718050.177 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:54:10.177Z,1591718050.177 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.4,0000.,000 2020-06-09T15:54:55.845Z,1591718095.845 [DVL_micro](ERROR): Failed to parse: :R99,+99999.99,+9999.99 2020-06-09T15:55:03.940Z,1591718103.940 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2020-06-09T15:55:03.940Z,1591718103.940 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:55:03.949Z,1591718103.949 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:55:04.354Z,1591718104.354 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:55:04.354Z,1591718104.354 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2020-06-09T15:55:11.185Z,1591718111.185 [DVL_micro](ERROR): Failed to parse:948,-00914,+00962,+00000,A 2020-06-09T15:55:36.640Z,1591718136.640 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+19.5,0000.0,1489.0,000 2020-06-09T15:56:19.869Z,1591718179.869 [DVL_micro](ERROR): Failed to parse: :WI,+01193,-01155,+00824,+00000,A 2020-06-09T15:58:04.959Z,1591718284.959 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2020-06-09T15:58:04.959Z,1591718284.959 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T15:58:04.969Z,1591718284.969 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T15:58:05.373Z,1591718285.373 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T15:58:05.373Z,1591718285.373 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2020-06-09T15:58:14.211Z,1591718294.211 [DVL_micro](ERROR): Failed to parse: :WI,+00142,-01215,+00887,+00000,A 2020-06-09T15:58:27.579Z,1591718307.579 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T15:53:27.4Z 2020-06-09T15:58:27.579Z,1591718307.579 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T15:58:27.579Z,1591718307.579 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T15:58:36.680Z,1591718316.680 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T150638/Courier0016.lzma 2020-06-09T15:58:37.245Z,1591718317.245 [DVL_micro](ERROR): Failed to parse: 0000000000,.5,0000.,000 2020-06-09T15:58:37.683Z,1591718317.683 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0016.lzma.bak 2020-06-09T15:58:37.683Z,1591718317.683 [DataOverHttps](INFO): SBD MOMSN=12374336 2020-06-09T15:58:56.993Z,1591718336.993 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200609T150638/Express0017.lzma 2020-06-09T15:58:57.995Z,1591718337.995 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0017.lzma.bak 2020-06-09T15:58:57.995Z,1591718337.995 [DataOverHttps](INFO): SBD MOMSN=12374338 2020-06-09T15:59:02.749Z,1591718342.749 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T15:59:02.750Z,1591718342.750 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T15:59:02.750Z,1591718342.750 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T15:59:20.476Z,1591718360.476 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T15:59:20.476Z,1591718360.476 [DVL_micro](ERROR): Failed to parse: :TS,000000,35,0000.0,1489.0,000 2020-06-09T16:00:25.915Z,1591718425.915 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T16:00:25.915Z,1591718425.915 [NAL9602] Data Fault, FailCount= 5 2020-06-09T16:00:25.915Z,1591718425.915 [NAL9602](ERROR): Data Fault 2020-06-09T16:00:25.946Z,1591718425.946 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T16:00:25.946Z,1591718425.946 [CBIT](CRITICAL): Data Fault in component: NAL9602 2020-06-09T16:00:26.362Z,1591718426.362 [NAL9602](INFO): Powering down 2020-06-09T16:00:26.420Z,1591718426.420 [CommandLine](FAULT): Scheduling is paused 2020-06-09T16:00:26.420Z,1591718426.420 [CBIT](INFO): Critical error at 20200609T160025 2020-06-09T16:00:26.420Z,1591718426.420 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-06-09T16:00:31.569Z,1591718431.569 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:00:31.570Z,1591718431.570 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+19.6,0000.0,148 2020-06-09T16:01:05.934Z,1591718465.934 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2020-06-09T16:01:05.934Z,1591718465.934 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:01:05.944Z,1591718465.944 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:01:06.354Z,1591718466.354 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:01:06.354Z,1591718466.354 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2020-06-09T16:01:12.378Z,1591718472.378 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:01:12.378Z,1591718472.378 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.61489.0,000 2020-06-09T16:02:25.946Z,1591718545.946 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T16:02:25.946Z,1591718545.946 [NAL9602] No Fault, FailCount= 5 2020-06-09T16:02:26.303Z,1591718546.303 [NAL9602](INFO): Powering up NAL9602 2020-06-09T16:02:37.211Z,1591718557.211 [NAL9602](INFO): NAL9602 initialized 2020-06-09T16:02:56.605Z,1591718576.605 [DVL_micro](ERROR): Failed to parse: :9,-01468+00000,A 2020-06-09T16:03:42.253Z,1591718622.253 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:03:42.254Z,1591718622.254 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,00.0,1489:WI,+0075,+01242,+ 2020-06-09T16:04:00.030Z,1591718640.030 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:04:00.030Z,1591718640.030 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.7,0000.,000 2020-06-09T16:04:03.307Z,1591718643.307 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T16:04:03.307Z,1591718643.307 [Default:CheckIn:C.Wait] Stopped 2020-06-09T16:04:03.307Z,1591718643.307 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T16:04:03.307Z,1591718643.307 [Default:CheckIn:D] Running Loop=1 2020-06-09T16:04:03.689Z,1591718643.689 [Default:CheckIn:D] Stopped 2020-06-09T16:04:03.689Z,1591718643.689 [Default:CheckIn:E] Running Loop=1 2020-06-09T16:04:04.094Z,1591718644.094 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.349036 min 2020-06-09T16:04:04.094Z,1591718644.094 [Default:CheckIn:E] Stopped 2020-06-09T16:04:04.094Z,1591718644.094 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T16:04:04.094Z,1591718644.094 [Default:CheckIn] Stopped 2020-06-09T16:04:04.094Z,1591718644.094 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T16:04:04.094Z,1591718644.094 [Default:CheckIn](INFO): Running loop #6 2020-06-09T16:04:04.094Z,1591718644.094 [Default:CheckIn] Running Loop=6 2020-06-09T16:04:04.095Z,1591718644.095 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T16:04:04.095Z,1591718644.095 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T16:04:06.916Z,1591718646.916 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2020-06-09T16:04:06.916Z,1591718646.916 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:04:06.942Z,1591718646.942 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:04:07.333Z,1591718647.333 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:04:07.333Z,1591718647.333 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2020-06-09T16:04:40.836Z,1591718680.836 [DVL_micro](ERROR): Failed to parse: 00000000019.7,0000.0,1489.0,000 2020-06-09T16:05:06.292Z,1591718706.292 [DVL_micro](ERROR): Failed to parse:000000000+19.7,0000.0,1489.0,000 2020-06-09T16:06:32.744Z,1591718792.744 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:06:32.744Z,1591718792.744 [DVL_micro](ERROR): Failed to parse::TS,000000,35.0,+190,1489.0,000 2020-06-09T16:07:07.914Z,1591718827.914 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2020-06-09T16:07:07.914Z,1591718827.914 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:07:07.924Z,1591718827.924 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:07:08.371Z,1591718828.371 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:07:08.371Z,1591718828.371 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2020-06-09T16:08:42.425Z,1591718922.425 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:08:42.425Z,1591718922.425 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.8,0000.,000 2020-06-09T16:09:04.295Z,1591718944.295 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T16:04:04.1Z 2020-06-09T16:09:04.295Z,1591718944.295 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T16:09:04.295Z,1591718944.295 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T16:09:12.873Z,1591718952.873 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20200609T150638/Courier0019.lzma 2020-06-09T16:09:13.875Z,1591718953.875 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0019.lzma.bak 2020-06-09T16:09:13.875Z,1591718953.875 [DataOverHttps](INFO): SBD MOMSN=12374342 2020-06-09T16:09:25.660Z,1591718965.660 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T16:09:25.661Z,1591718965.661 [DVL_micro](ERROR): Failed to parse: :RD,+9999.999,+9999.99,+9999.99 2020-06-09T16:09:33.093Z,1591718973.093 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20200609T150638/Express0020.lzma 2020-06-09T16:09:34.095Z,1591718974.095 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0020.lzma.bak 2020-06-09T16:09:34.095Z,1591718974.095 [DataOverHttps](INFO): SBD MOMSN=12374345 2020-06-09T16:09:38.638Z,1591718978.638 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T16:09:38.638Z,1591718978.638 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T16:09:38.638Z,1591718978.638 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T16:10:08.907Z,1591719008.907 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21 2020-06-09T16:10:08.907Z,1591719008.907 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:10:08.917Z,1591719008.917 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:10:09.339Z,1591719009.339 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:10:09.339Z,1591719009.339 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21 2020-06-09T16:12:39.571Z,1591719159.571 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T16:12:39.571Z,1591719159.571 [NAL9602] Data Fault, FailCount= 1 2020-06-09T16:12:39.571Z,1591719159.571 [NAL9602](ERROR): Data Fault 2020-06-09T16:12:39.629Z,1591719159.629 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T16:12:39.971Z,1591719159.971 [NAL9602](INFO): Powering down 2020-06-09T16:12:40.818Z,1591719160.818 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T16:12:40.818Z,1591719160.818 [NAL9602] No Fault, FailCount= 1 2020-06-09T16:12:46.442Z,1591719166.442 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:12:46.442Z,1591719166.442 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,,+00496,-01233,+01109,+00000,A 2020-06-09T16:13:09.907Z,1591719189.907 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22 2020-06-09T16:13:09.907Z,1591719189.907 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:13:09.916Z,1591719189.916 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:13:10.277Z,1591719190.277 [NAL9602](INFO): Powering up NAL9602 2020-06-09T16:13:10.332Z,1591719190.332 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:13:10.332Z,1591719190.332 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22 2020-06-09T16:13:21.183Z,1591719201.183 [NAL9602](INFO): NAL9602 initialized 2020-06-09T16:14:39.215Z,1591719279.215 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T16:14:39.215Z,1591719279.215 [Default:CheckIn:C.Wait] Stopped 2020-06-09T16:14:39.215Z,1591719279.215 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T16:14:39.215Z,1591719279.215 [Default:CheckIn:D] Running Loop=1 2020-06-09T16:14:39.606Z,1591719279.606 [Default:CheckIn:D] Stopped 2020-06-09T16:14:39.606Z,1591719279.606 [Default:CheckIn:E] Running Loop=1 2020-06-09T16:14:40.013Z,1591719280.013 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.947652 min 2020-06-09T16:14:40.013Z,1591719280.013 [Default:CheckIn:E] Stopped 2020-06-09T16:14:40.013Z,1591719280.013 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T16:14:40.013Z,1591719280.013 [Default:CheckIn] Stopped 2020-06-09T16:14:40.013Z,1591719280.013 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T16:14:40.014Z,1591719280.014 [Default:CheckIn](INFO): Running loop #7 2020-06-09T16:14:40.014Z,1591719280.014 [Default:CheckIn] Running Loop=7 2020-06-09T16:14:40.014Z,1591719280.014 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T16:14:40.014Z,1591719280.014 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T16:16:10.904Z,1591719370.904 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23 2020-06-09T16:16:10.904Z,1591719370.904 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:16:10.914Z,1591719370.914 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:16:11.330Z,1591719371.330 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:16:11.330Z,1591719371.330 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23 2020-06-09T16:16:17.333Z,1591719377.333 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T16:16:17.333Z,1591719377.333 [DVL_micro](ERROR): Failed to parse: :BI,01023,+00893,+00000,I 2020-06-09T16:17:15.916Z,1591719435.916 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+9999.99 2020-06-09T16:17:56.319Z,1591719476.319 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T16:17:56.319Z,1591719476.319 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.999 2020-06-09T16:18:16.918Z,1591719496.918 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: -1171 2020-06-09T16:18:16.920Z,1591719496.920 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2020-06-09T16:19:11.898Z,1591719551.898 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24 2020-06-09T16:19:11.898Z,1591719551.898 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:19:11.928Z,1591719551.928 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:19:12.307Z,1591719552.307 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:19:12.307Z,1591719552.307 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24 2020-06-09T16:19:17.916Z,1591719557.916 [DVL_micro](ERROR): Failed to parse: :T000000000.1,0000.0,148 2020-06-09T16:19:40.176Z,1591719580.176 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T16:14:40.0Z 2020-06-09T16:19:40.176Z,1591719580.176 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T16:19:40.176Z,1591719580.176 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T16:19:49.368Z,1591719589.368 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T150638/Courier0022.lzma 2020-06-09T16:19:50.371Z,1591719590.371 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0022.lzma.bak 2020-06-09T16:19:50.371Z,1591719590.371 [DataOverHttps](INFO): SBD MOMSN=12374350 2020-06-09T16:20:10.174Z,1591719610.174 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200609T150638/Express0023.lzma 2020-06-09T16:20:11.177Z,1591719611.177 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0023.lzma.bak 2020-06-09T16:20:11.177Z,1591719611.177 [DataOverHttps](INFO): SBD MOMSN=12374352 2020-06-09T16:20:15.735Z,1591719615.735 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T16:20:15.735Z,1591719615.735 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T16:20:15.735Z,1591719615.735 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T16:21:02.154Z,1591719662.154 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:21:02.154Z,1591719662.154 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0000.0,1489.0,0-00585,01134,+00000,A 2020-06-09T16:21:45.383Z,1591719705.383 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T16:21:45.383Z,1591719705.383 [DVL_micro](ERROR): Failed to parse: :BI,+00803,-01406,+0110,I 2020-06-09T16:22:03.157Z,1591719723.157 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+20.2,0000.0,1489.0,000 2020-06-09T16:22:12.878Z,1591719732.878 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25 2020-06-09T16:22:12.878Z,1591719732.878 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:22:12.888Z,1591719732.888 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:22:13.341Z,1591719733.341 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:22:13.341Z,1591719733.341 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25 2020-06-09T16:23:23.543Z,1591719803.543 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T16:23:23.543Z,1591719803.543 [NAL9602] Data Fault, FailCount= 2 2020-06-09T16:23:23.543Z,1591719803.543 [NAL9602](ERROR): Data Fault 2020-06-09T16:23:23.611Z,1591719803.611 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T16:23:23.951Z,1591719803.951 [NAL9602](INFO): Powering down 2020-06-09T16:23:24.798Z,1591719804.798 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T16:23:24.798Z,1591719804.798 [NAL9602] No Fault, FailCount= 2 2020-06-09T16:23:54.252Z,1591719834.252 [NAL9602](INFO): Powering up NAL9602 2020-06-09T16:24:05.169Z,1591719845.169 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:24:05.169Z,1591719845.169 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,32,0000.0,1489.0,000 2020-06-09T16:24:05.170Z,1591719845.170 [NAL9602](INFO): NAL9602 initialized 2020-06-09T16:25:13.881Z,1591719913.881 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 26 2020-06-09T16:25:13.881Z,1591719913.881 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:25:13.918Z,1591719913.918 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:25:14.298Z,1591719914.298 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:25:14.298Z,1591719914.298 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 26 2020-06-09T16:25:16.327Z,1591719916.327 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T16:25:16.327Z,1591719916.327 [Default:CheckIn:C.Wait] Stopped 2020-06-09T16:25:16.327Z,1591719916.327 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T16:25:16.327Z,1591719916.327 [Default:CheckIn:D] Running Loop=1 2020-06-09T16:25:16.695Z,1591719916.695 [Default:CheckIn:D] Stopped 2020-06-09T16:25:16.695Z,1591719916.695 [Default:CheckIn:E] Running Loop=1 2020-06-09T16:25:17.101Z,1591719917.101 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.565796 min 2020-06-09T16:25:17.101Z,1591719917.101 [Default:CheckIn:E] Stopped 2020-06-09T16:25:17.101Z,1591719917.101 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T16:25:17.101Z,1591719917.101 [Default:CheckIn] Stopped 2020-06-09T16:25:17.102Z,1591719917.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T16:25:17.102Z,1591719917.102 [Default:CheckIn](INFO): Running loop #8 2020-06-09T16:25:17.102Z,1591719917.102 [Default:CheckIn] Running Loop=8 2020-06-09T16:25:17.102Z,1591719917.102 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T16:25:17.102Z,1591719917.102 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T16:25:34.045Z,1591719934.045 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T16:25:34.045Z,1591719934.045 [DVL_micro](ERROR): Failed to parse: :BI,-0020,+01311,+00000,I 2020-06-09T16:25:49.392Z,1591719949.392 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:25:49.392Z,1591719949.392 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,00.0,148 2020-06-09T16:26:08.469Z,1591719968.469 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2020-06-09T16:27:15.848Z,1591720035.848 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:27:15.848Z,1591720035.848 [DVL_micro](ERROR): Failed to parse: :TS,000000005.0,+20.,1489.0,000 2020-06-09T16:28:14.886Z,1591720094.886 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 27 2020-06-09T16:28:14.886Z,1591720094.886 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:28:14.896Z,1591720094.896 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:28:15.305Z,1591720095.305 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:28:15.305Z,1591720095.305 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 27 2020-06-09T16:29:25.550Z,1591720165.550 [DVL_micro](ERROR): Failed to parse: :B,-01171,+01259, 2020-06-09T16:29:29.492Z,1591720169.492 [CommandLine](IMPORTANT): got command show variable neutral 2020-06-09T16:29:29.503Z,1591720169.503 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter) 2020-06-09T16:29:29.547Z,1591720169.547 [CommandLine](IMPORTANT): Config/Simulator.buoyancyNeutralOffset (cubic_centimeter) 2020-06-09T16:29:35.826Z,1591720175.826 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral 2020-06-09T16:29:35.827Z,1591720175.827 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 242.907928 cc 2020-06-09T16:30:17.311Z,1591720217.311 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T16:25:17.1Z 2020-06-09T16:30:17.311Z,1591720217.311 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T16:30:17.311Z,1591720217.311 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T16:30:26.264Z,1591720226.264 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T150638/Courier0025.lzma 2020-06-09T16:30:27.267Z,1591720227.267 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0025.lzma.bak 2020-06-09T16:30:27.267Z,1591720227.267 [DataOverHttps](INFO): SBD MOMSN=12374356 2020-06-09T16:30:46.733Z,1591720246.733 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20200609T150638/Express0026.lzma 2020-06-09T16:30:47.735Z,1591720247.735 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0026.lzma.bak 2020-06-09T16:30:47.735Z,1591720247.735 [DataOverHttps](INFO): SBD MOMSN=12374358 2020-06-09T16:30:52.502Z,1591720252.502 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T16:30:52.502Z,1591720252.502 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T16:30:52.502Z,1591720252.502 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T16:31:15.912Z,1591720275.912 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 28 2020-06-09T16:31:15.912Z,1591720275.912 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:31:15.922Z,1591720275.922 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:31:16.330Z,1591720276.330 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:31:16.331Z,1591720276.331 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 28 2020-06-09T16:32:20.933Z,1591720340.933 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:32:20.933Z,1591720340.933 [DVL_micro](ERROR): Failed to parse: :TS,000000000000+20.4,0000.0,1489.0,000 2020-06-09T16:33:21.938Z,1591720401.938 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:33:21.938Z,1591720401.938 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.4,0000.,000 2020-06-09T16:34:06.371Z,1591720446.371 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T16:34:06.371Z,1591720446.371 [NAL9602] Data Fault, FailCount= 3 2020-06-09T16:34:06.371Z,1591720446.371 [NAL9602](ERROR): Data Fault 2020-06-09T16:34:06.439Z,1591720446.439 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T16:34:06.784Z,1591720446.784 [NAL9602](INFO): Powering down 2020-06-09T16:34:07.646Z,1591720447.646 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T16:34:07.646Z,1591720447.646 [NAL9602] No Fault, FailCount= 3 2020-06-09T16:34:16.903Z,1591720456.903 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 29 2020-06-09T16:34:16.903Z,1591720456.903 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:34:16.913Z,1591720456.913 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:34:17.317Z,1591720457.317 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:34:17.317Z,1591720457.317 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 29 2020-06-09T16:34:22.940Z,1591720462.940 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:34:22.940Z,1591720462.940 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+2.0,1489.0,000 2020-06-09T16:34:37.079Z,1591720477.079 [NAL9602](INFO): Powering up NAL9602 2020-06-09T16:34:40.712Z,1591720480.712 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:34:40.712Z,1591720480.712 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+20.41489.0,000 2020-06-09T16:34:47.999Z,1591720487.999 [NAL9602](INFO): NAL9602 initialized 2020-06-09T16:35:23.944Z,1591720523.944 [DVL_micro](ERROR): only read 0 of 4 data items 2020-06-09T16:35:23.944Z,1591720523.944 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.99,+9999.99,+9999.99 2020-06-09T16:35:53.071Z,1591720553.071 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T16:35:53.071Z,1591720553.071 [Default:CheckIn:C.Wait] Stopped 2020-06-09T16:35:53.071Z,1591720553.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T16:35:53.071Z,1591720553.071 [Default:CheckIn:D] Running Loop=1 2020-06-09T16:35:53.467Z,1591720553.467 [Default:CheckIn:D] Stopped 2020-06-09T16:35:53.467Z,1591720553.467 [Default:CheckIn:E] Running Loop=1 2020-06-09T16:35:53.931Z,1591720553.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.178670 min 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn:E] Stopped 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn] Stopped 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn](INFO): Running loop #9 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn] Running Loop=9 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T16:35:53.932Z,1591720553.932 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T16:36:25.029Z,1591720585.029 [DVL_micro](ERROR): DVL uart error: serial timeout 2020-06-09T16:36:25.029Z,1591720585.029 [DVL_micro] Communications Fault, FailCount= 1 2020-06-09T16:36:25.029Z,1591720585.029 [DVL_micro](ERROR): Communications Fault 2020-06-09T16:36:25.029Z,1591720585.029 [DVL_micro](ERROR): Failed to parse: 2020-06-09T16:36:25.081Z,1591720585.081 [CBIT](ERROR): Communications Fault in component: DVL_micro 2020-06-09T16:36:25.453Z,1591720585.453 [DVL_micro](INFO): Powering down 2020-06-09T16:36:26.227Z,1591720586.227 [CBIT](INFO): Clearing failed state for component DVL_micro 2020-06-09T16:36:26.227Z,1591720586.227 [DVL_micro] No Fault, FailCount= 1 2020-06-09T16:37:17.893Z,1591720637.893 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 30 2020-06-09T16:37:17.893Z,1591720637.893 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:37:17.903Z,1591720637.903 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:37:18.318Z,1591720638.318 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:37:18.318Z,1591720638.318 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 30 2020-06-09T16:37:35.244Z,1591720655.244 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:37:35.244Z,1591720655.244 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2020-06-09T16:38:54.020Z,1591720734.020 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:38:54.021Z,1591720734.021 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,36,0000.0,1489.0,000 2020-06-09T16:40:18.884Z,1591720818.884 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 31 2020-06-09T16:40:18.884Z,1591720818.884 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:40:18.912Z,1591720818.912 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:40:19.356Z,1591720819.356 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:40:19.356Z,1591720819.356 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 31 2020-06-09T16:40:54.058Z,1591720854.058 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T16:35:53.9Z 2020-06-09T16:40:54.059Z,1591720854.059 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T16:40:54.059Z,1591720854.059 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T16:41:03.240Z,1591720863.240 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T150638/Courier0028.lzma 2020-06-09T16:41:04.243Z,1591720864.243 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0028.lzma.bak 2020-06-09T16:41:04.243Z,1591720864.243 [DataOverHttps](INFO): SBD MOMSN=12374367 2020-06-09T16:41:21.480Z,1591720881.480 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:41:21.481Z,1591720881.481 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+20.6,489.0,000 2020-06-09T16:41:25.769Z,1591720885.769 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200609T150638/Express0029.lzma 2020-06-09T16:41:26.771Z,1591720886.771 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0029.lzma.bak 2020-06-09T16:41:26.771Z,1591720886.771 [DataOverHttps](INFO): SBD MOMSN=12374369 2020-06-09T16:41:31.359Z,1591720891.359 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T16:41:31.359Z,1591720891.359 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T16:41:31.359Z,1591720891.359 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T16:42:07.143Z,1591720927.143 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2020-06-09T16:43:19.873Z,1591720999.873 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 32 2020-06-09T16:43:19.873Z,1591720999.873 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:43:19.899Z,1591720999.899 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:43:20.295Z,1591721000.295 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:43:20.295Z,1591721000.295 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 32 2020-06-09T16:43:48.946Z,1591721028.946 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:43:48.946Z,1591721028.946 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.6,0000.0,1489:WI,+00553,-01265,+01217,+00000,A 2020-06-09T16:44:49.948Z,1591721089.948 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:44:49.949Z,1591721089.949 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.7,00000,000 2020-06-09T16:44:50.351Z,1591721090.351 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T16:44:50.351Z,1591721090.351 [NAL9602] Data Fault, FailCount= 4 2020-06-09T16:44:50.351Z,1591721090.351 [NAL9602](ERROR): Data Fault 2020-06-09T16:44:50.415Z,1591721090.415 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T16:44:50.755Z,1591721090.755 [NAL9602](INFO): Powering down 2020-06-09T16:44:51.589Z,1591721091.589 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T16:44:51.589Z,1591721091.589 [NAL9602] No Fault, FailCount= 4 2020-06-09T16:45:07.728Z,1591721107.728 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2020-06-09T16:45:21.051Z,1591721121.051 [NAL9602](INFO): Powering up NAL9602 2020-06-09T16:45:27.943Z,1591721127.943 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2020-06-09T16:45:27.944Z,1591721127.944 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2020-06-09T16:45:27.947Z,1591721127.947 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2020-06-09T16:45:31.964Z,1591721131.964 [NAL9602](INFO): NAL9602 initialized 2020-06-09T16:45:53.376Z,1591721153.376 [DVL_micro](ERROR): Failed to parse:99.99,++9999.99,+ 2020-06-09T16:46:20.886Z,1591721180.886 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 33 2020-06-09T16:46:20.886Z,1591721180.886 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:46:20.915Z,1591721180.915 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:46:21.301Z,1591721181.301 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:46:21.301Z,1591721181.301 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 33 2020-06-09T16:46:31.778Z,1591721191.778 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T16:46:31.778Z,1591721191.778 [Default:CheckIn:C.Wait] Stopped 2020-06-09T16:46:31.778Z,1591721191.778 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T16:46:31.778Z,1591721191.778 [Default:CheckIn:D] Running Loop=1 2020-06-09T16:46:32.195Z,1591721192.195 [Default:CheckIn:D] Stopped 2020-06-09T16:46:32.195Z,1591721192.195 [Default:CheckIn:E] Running Loop=1 2020-06-09T16:46:32.599Z,1591721192.599 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.824129 min 2020-06-09T16:46:32.599Z,1591721192.599 [Default:CheckIn:E] Stopped 2020-06-09T16:46:32.599Z,1591721192.599 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T16:46:32.599Z,1591721192.599 [Default:CheckIn] Stopped 2020-06-09T16:46:32.600Z,1591721192.600 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T16:46:32.600Z,1591721192.600 [Default:CheckIn](INFO): Running loop #10 2020-06-09T16:46:32.600Z,1591721192.600 [Default:CheckIn] Running Loop=10 2020-06-09T16:46:32.600Z,1591721192.600 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T16:46:32.600Z,1591721192.600 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T16:46:33.871Z,1591721193.871 [DataOverHttps](IMPORTANT): SBD MTMSN=20200609T164623 2020-06-09T16:46:41.173Z,1591721201.173 [DataOverHttps](INFO): Received command:restart app 2020-06-09T16:46:41.225Z,1591721201.225 [CommandLine](IMPORTANT): got command restart application 2020-06-09T16:46:42.229Z,1591721202.229 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:42.229Z,1591721202.229 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.309Z,1591721202.309 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-06-09T16:46:42.309Z,1591721202.309 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.310Z,1591721202.310 [CommandLine](INFO): Join timeout helper Thread ID is 612 2020-06-09T16:46:42.311Z,1591721202.311 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-06-09T16:46:42.311Z,1591721202.311 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.311Z,1591721202.311 [NavChartDb](INFO): Join timeout helper Thread ID is 613 2020-06-09T16:46:42.417Z,1591721202.417 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:42.417Z,1591721202.417 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.421Z,1591721202.421 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-06-09T16:46:42.421Z,1591721202.421 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.421Z,1591721202.421 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 614 2020-06-09T16:46:42.573Z,1591721202.573 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:42.573Z,1591721202.573 [WetLabsBB2FL](INFO): Powering down 2020-06-09T16:46:42.574Z,1591721202.574 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.581Z,1591721202.581 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-06-09T16:46:42.581Z,1591721202.581 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.581Z,1591721202.581 [CTD_Seabird](INFO): Join timeout helper Thread ID is 615 2020-06-09T16:46:42.849Z,1591721202.849 [CTD_Seabird](INFO): Powering down 2020-06-09T16:46:42.861Z,1591721202.861 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:42.861Z,1591721202.861 [CTD_Seabird](INFO): Powering down 2020-06-09T16:46:42.873Z,1591721202.873 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.881Z,1591721202.881 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-06-09T16:46:42.881Z,1591721202.881 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:42.881Z,1591721202.881 [Radio_Surface](INFO): Join timeout helper Thread ID is 616 2020-06-09T16:46:43.245Z,1591721203.245 [Radio_Surface](INFO): Powering down 2020-06-09T16:46:43.246Z,1591721203.246 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:43.246Z,1591721203.246 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:43.250Z,1591721203.250 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-06-09T16:46:43.250Z,1591721203.250 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:43.250Z,1591721203.250 [DataOverHttps](INFO): Join timeout helper Thread ID is 617 2020-06-09T16:46:44.181Z,1591721204.181 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:44.181Z,1591721204.181 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.189Z,1591721204.189 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-06-09T16:46:44.190Z,1591721204.190 [logger ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.190Z,1591721204.190 [logger](INFO): Join timeout helper Thread ID is 618 2020-06-09T16:46:44.205Z,1591721204.205 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:44.205Z,1591721204.205 [logger ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.209Z,1591721204.209 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-06-09T16:46:44.210Z,1591721204.210 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.210Z,1591721204.210 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-06-09T16:46:44.210Z,1591721204.210 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.210Z,1591721204.210 [controlThread](INFO): Join timeout helper Thread ID is 619 2020-06-09T16:46:44.261Z,1591721204.261 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-06-09T16:46:44.261Z,1591721204.261 [controlThread](DEBUG): Uninitializing ControlThread 2020-06-09T16:46:44.261Z,1591721204.261 [AHRS_M2](INFO): Powering down 2020-06-09T16:46:44.405Z,1591721204.405 [DVL_micro](INFO): Powering down 2020-06-09T16:46:44.406Z,1591721204.406 [NAL9602](INFO): Powering down 2020-06-09T16:46:44.407Z,1591721204.407 [DAT](INFO): Powering down 2020-06-09T16:46:44.544Z,1591721204.544 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-06-09T16:46:44.545Z,1591721204.545 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-06-09T16:46:44.545Z,1591721204.545 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-06-09T16:46:44.546Z,1591721204.546 [MissionManager](INFO): Uninitializing Mission Default 2020-06-09T16:46:44.546Z,1591721204.546 [Default] Stopped 2020-06-09T16:46:44.546Z,1591721204.546 [Default](DEBUG): Aggregate::uninitialize Default 2020-06-09T16:46:44.546Z,1591721204.546 [Default:B.GoToSurface] Stopped 2020-06-09T16:46:44.546Z,1591721204.546 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-06-09T16:46:44.546Z,1591721204.546 [Default:CheckIn] Stopped 2020-06-09T16:46:44.546Z,1591721204.546 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T16:46:44.547Z,1591721204.547 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T16:46:44.549Z,1591721204.549 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-06-09T16:46:44.549Z,1591721204.549 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-06-09T16:46:44.550Z,1591721204.550 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-06-09T16:46:44.550Z,1591721204.550 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-06-09T16:46:44.550Z,1591721204.550 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-06-09T16:46:44.550Z,1591721204.550 [BuoyancyServo](INFO): Powering down 2020-06-09T16:46:44.565Z,1591721204.565 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-06-09T16:46:44.565Z,1591721204.565 [ElevatorServo](INFO): Powering down 2020-06-09T16:46:44.566Z,1591721204.566 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-06-09T16:46:44.566Z,1591721204.566 [MassServo](INFO): Powering down 2020-06-09T16:46:44.567Z,1591721204.567 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-06-09T16:46:44.567Z,1591721204.567 [RudderServo](INFO): Powering down 2020-06-09T16:46:44.568Z,1591721204.568 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-06-09T16:46:44.568Z,1591721204.568 [ThrusterServo](INFO): Powering down 2020-06-09T16:46:44.568Z,1591721204.568 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-06-09T16:46:44.569Z,1591721204.569 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-06-09T16:46:44.569Z,1591721204.569 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-06-09T16:46:44.569Z,1591721204.569 [CBIT](DEBUG): Powering off loads. 2020-06-09T16:46:44.581Z,1591721204.581 [CBIT](DEBUG): Disabling WDT. 2020-06-09T16:46:44.593Z,1591721204.593 [CBIT](DEBUG): Opening all GF detection circuits. 2020-06-09T16:46:44.594Z,1591721204.594 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.684Z,1591721204.684 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.692Z,1591721204.692 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.751Z,1591721204.751 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.756Z,1591721204.756 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.781Z,1591721204.781 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-06-09T16:46:44.830Z,1591721204.830 [logger ThreadHandler](INFO): Thread cancelled.