2019-10-01T15:48:05.795Z,1569944885.795 [Supervisor](DEBUG): Initializing supervisor. 2019-10-01T15:48:05.797Z,1569944885.797 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-10-01T15:48:05.798Z,1569944885.798 [SyncHandler](INFO): Protected caller Thread ID is 3706 2019-10-01T15:48:05.798Z,1569944885.798 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-10-01T15:48:05.799Z,1569944885.799 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-10-01T15:48:05.800Z,1569944885.800 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3707 2019-10-01T15:48:05.802Z,1569944885.802 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-10-01T15:48:05.813Z,1569944885.813 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-10-01T15:48:05.814Z,1569944885.814 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-10-01T15:48:05.815Z,1569944885.815 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3708 2019-10-01T15:48:05.815Z,1569944885.815 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-10-01T15:48:05.816Z,1569944885.816 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-10-01T15:48:05.817Z,1569944885.817 [logger ThreadHandler](INFO): Protected caller Thread ID is 3709 2019-10-01T15:48:05.819Z,1569944885.819 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-10-01T15:48:05.819Z,1569944885.819 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-10-01T15:48:05.821Z,1569944885.821 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-10-01T15:48:05.913Z,1569944885.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-10-01T15:48:05.914Z,1569944885.914 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-10-01T15:48:06.111Z,1569944886.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-10-01T15:48:06.112Z,1569944886.112 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-10-01T15:48:06.244Z,1569944886.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-10-01T15:48:06.244Z,1569944886.244 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-10-01T15:48:06.802Z,1569944886.802 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-10-01T15:48:06.802Z,1569944886.802 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-10-01T15:48:07.233Z,1569944887.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-10-01T15:48:07.234Z,1569944887.234 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-10-01T15:48:07.693Z,1569944887.693 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-10-01T15:48:07.694Z,1569944887.694 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-10-01T15:48:07.988Z,1569944887.988 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-10-01T15:48:07.988Z,1569944887.988 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-10-01T15:48:08.383Z,1569944888.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-10-01T15:48:08.384Z,1569944888.384 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-10-01T15:48:08.768Z,1569944888.768 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-10-01T15:48:08.769Z,1569944888.769 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-10-01T15:48:08.913Z,1569944888.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-10-01T15:48:08.913Z,1569944888.913 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-10-01T15:48:09.015Z,1569944889.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-10-01T15:48:09.016Z,1569944889.016 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-10-01T15:48:09.095Z,1569944889.095 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-10-01T15:48:09.194Z,1569944889.194 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-10-01T15:48:09.194Z,1569944889.194 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-10-01T15:48:09.381Z,1569944889.381 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-10-01T15:48:09.382Z,1569944889.382 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-10-01T15:48:09.583Z,1569944889.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-10-01T15:48:09.586Z,1569944889.586 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2019-10-01T15:48:09.586Z,1569944889.586 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2019-10-01T15:48:09.667Z,1569944889.667 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2019-10-01T15:48:09.889Z,1569944889.889 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-10-01T15:48:09.890Z,1569944889.890 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2019-10-01T15:48:09.982Z,1569944889.982 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2019-10-01T15:48:10.141Z,1569944890.141 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2019-10-01T15:48:10.337Z,1569944890.337 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2019-10-01T15:48:10.463Z,1569944890.463 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2019-10-01T15:48:10.732Z,1569944890.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2019-10-01T15:48:10.941Z,1569944890.941 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2019-10-01T15:48:11.306Z,1569944891.306 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2019-10-01T15:48:11.412Z,1569944891.412 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2019-10-01T15:48:11.509Z,1569944891.509 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2019-10-01T15:48:11.509Z,1569944891.509 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-10-01T15:48:11.511Z,1569944891.511 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-10-01T15:48:11.612Z,1569944891.612 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-10-01T15:48:11.612Z,1569944891.612 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-10-01T15:48:11.719Z,1569944891.719 [BuoyancyServo] Loaded 2019-10-01T15:48:11.719Z,1569944891.719 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-10-01T15:48:11.735Z,1569944891.735 [ElevatorServo] Loaded 2019-10-01T15:48:11.735Z,1569944891.735 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-10-01T15:48:11.750Z,1569944891.750 [MassServo] Loaded 2019-10-01T15:48:11.750Z,1569944891.750 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-10-01T15:48:11.765Z,1569944891.765 [RudderServo] Loaded 2019-10-01T15:48:11.766Z,1569944891.766 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-10-01T15:48:11.780Z,1569944891.780 [ThrusterServo] Loaded 2019-10-01T15:48:11.780Z,1569944891.780 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-10-01T15:48:11.781Z,1569944891.781 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-10-01T15:48:11.781Z,1569944891.781 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-10-01T15:48:11.915Z,1569944891.915 [SBIT](DEBUG): Construct Startup Built In Test. 2019-10-01T15:48:11.945Z,1569944891.945 [SBIT] Loaded 2019-10-01T15:48:11.945Z,1569944891.945 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-10-01T15:48:11.946Z,1569944891.946 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-10-01T15:48:11.974Z,1569944891.974 [IBIT] Loaded 2019-10-01T15:48:11.974Z,1569944891.974 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-10-01T15:48:11.977Z,1569944891.977 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-10-01T15:48:12.375Z,1569944892.375 [CBIT] Loaded 2019-10-01T15:48:12.376Z,1569944892.376 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-10-01T15:48:12.376Z,1569944892.376 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-10-01T15:48:12.377Z,1569944892.377 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-10-01T15:48:12.559Z,1569944892.559 [Aanderaa_O2] Loaded 2019-10-01T15:48:12.559Z,1569944892.559 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2019-10-01T15:48:12.569Z,1569944892.569 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-10-01T15:48:12.574Z,1569944892.574 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-10-01T15:48:12.576Z,1569944892.576 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-10-01T15:48:12.581Z,1569944892.581 [CTD_Seabird](INFO): created writer for : depth 2019-10-01T15:48:12.581Z,1569944892.581 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-10-01T15:48:12.586Z,1569944892.586 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-10-01T15:48:12.587Z,1569944892.587 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-10-01T15:48:12.592Z,1569944892.592 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-10-01T15:48:12.593Z,1569944892.593 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-10-01T15:48:12.598Z,1569944892.598 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-10-01T15:48:12.599Z,1569944892.599 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-10-01T15:48:12.604Z,1569944892.604 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-10-01T15:48:12.605Z,1569944892.605 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-10-01T15:48:12.610Z,1569944892.610 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-10-01T15:48:12.637Z,1569944892.637 [CTD_Seabird] Loaded 2019-10-01T15:48:12.637Z,1569944892.637 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-10-01T15:48:12.638Z,1569944892.638 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4066B4E0 2019-10-01T15:48:12.639Z,1569944892.639 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3789 2019-10-01T15:48:12.670Z,1569944892.670 [ESPComponent] Loaded 2019-10-01T15:48:12.670Z,1569944892.670 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-10-01T15:48:12.684Z,1569944892.684 [PAR_Licor] Loaded 2019-10-01T15:48:12.685Z,1569944892.685 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-10-01T15:48:12.691Z,1569944892.691 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2019-10-01T15:48:12.691Z,1569944892.691 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2019-10-01T15:48:12.695Z,1569944892.695 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2019-10-01T15:48:12.695Z,1569944892.695 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2019-10-01T15:48:12.700Z,1569944892.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2019-10-01T15:48:12.700Z,1569944892.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2019-10-01T15:48:12.704Z,1569944892.704 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2019-10-01T15:48:12.704Z,1569944892.704 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2019-10-01T15:48:12.709Z,1569944892.709 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2019-10-01T15:48:12.709Z,1569944892.709 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2019-10-01T15:48:12.714Z,1569944892.714 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2019-10-01T15:48:12.714Z,1569944892.714 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2019-10-01T15:48:12.718Z,1569944892.718 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2019-10-01T15:48:12.718Z,1569944892.718 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2019-10-01T15:48:12.723Z,1569944892.723 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.727Z,1569944892.727 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.728Z,1569944892.728 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.728Z,1569944892.728 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.733Z,1569944892.733 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.733Z,1569944892.733 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.737Z,1569944892.737 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.737Z,1569944892.737 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T15:48:12.742Z,1569944892.742 [WetLabsBB2FL] Loaded 2019-10-01T15:48:12.742Z,1569944892.742 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-10-01T15:48:12.743Z,1569944892.743 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4069B4E0 2019-10-01T15:48:12.744Z,1569944892.744 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3790 2019-10-01T15:48:12.744Z,1569944892.744 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-10-01T15:48:12.745Z,1569944892.745 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-10-01T15:48:12.786Z,1569944892.786 [DepthRateCalculator] Loaded 2019-10-01T15:48:12.786Z,1569944892.786 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-10-01T15:48:12.792Z,1569944892.792 [PitchRateCalculator] Loaded 2019-10-01T15:48:12.792Z,1569944892.792 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-10-01T15:48:12.808Z,1569944892.808 [SpeedCalculator] Loaded 2019-10-01T15:48:12.809Z,1569944892.809 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-10-01T15:48:12.830Z,1569944892.830 [TempGradientCalculator] Loaded 2019-10-01T15:48:12.830Z,1569944892.830 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-10-01T15:48:12.836Z,1569944892.836 [YawRateCalculator] Loaded 2019-10-01T15:48:12.836Z,1569944892.836 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-10-01T15:48:12.870Z,1569944892.870 [ElevatorOffsetCalculator] Loaded 2019-10-01T15:48:12.870Z,1569944892.870 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-10-01T15:48:12.871Z,1569944892.871 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-10-01T15:48:12.871Z,1569944892.871 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-10-01T15:48:12.903Z,1569944892.903 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-10-01T15:48:12.904Z,1569944892.904 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-10-01T15:48:13.008Z,1569944893.008 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-10-01T15:48:13.008Z,1569944893.008 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-10-01T15:48:13.030Z,1569944893.030 [NavChart] Loaded 2019-10-01T15:48:13.030Z,1569944893.030 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-10-01T15:48:13.034Z,1569944893.034 [UniversalFixResidualReporter] Loaded 2019-10-01T15:48:13.034Z,1569944893.034 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-10-01T15:48:13.035Z,1569944893.035 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-10-01T15:48:13.035Z,1569944893.035 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-10-01T15:48:13.271Z,1569944893.271 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-10-01T15:48:13.276Z,1569944893.276 [AHRS_M2](INFO): created writer for : platform_orientation 2019-10-01T15:48:13.276Z,1569944893.276 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-10-01T15:48:13.282Z,1569944893.282 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-10-01T15:48:13.282Z,1569944893.282 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-10-01T15:48:13.287Z,1569944893.287 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-10-01T15:48:13.288Z,1569944893.288 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-10-01T15:48:13.293Z,1569944893.293 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-10-01T15:48:13.368Z,1569944893.368 [AHRS_M2] Loaded 2019-10-01T15:48:13.368Z,1569944893.368 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-10-01T15:48:13.444Z,1569944893.444 [DataOverHttps] Loaded 2019-10-01T15:48:13.444Z,1569944893.444 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-10-01T15:48:13.446Z,1569944893.446 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409634E0 2019-10-01T15:48:13.446Z,1569944893.446 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3791 2019-10-01T15:48:13.460Z,1569944893.460 [Depth_Keller] Loaded 2019-10-01T15:48:13.460Z,1569944893.460 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-10-01T15:48:13.465Z,1569944893.465 [DropWeight] Loaded 2019-10-01T15:48:13.465Z,1569944893.465 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-10-01T15:48:13.512Z,1569944893.512 [DVL_micro] Loaded 2019-10-01T15:48:13.512Z,1569944893.512 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-10-01T15:48:13.605Z,1569944893.605 [NAL9602] Loaded 2019-10-01T15:48:13.606Z,1569944893.606 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-10-01T15:48:13.611Z,1569944893.611 [Onboard] Loaded 2019-10-01T15:48:13.611Z,1569944893.611 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-10-01T15:48:13.614Z,1569944893.614 [Radio_Surface] Loaded 2019-10-01T15:48:13.615Z,1569944893.615 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-10-01T15:48:13.616Z,1569944893.616 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409934E0 2019-10-01T15:48:13.616Z,1569944893.616 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3792 2019-10-01T15:48:13.743Z,1569944893.743 [DAT] Loaded 2019-10-01T15:48:13.743Z,1569944893.743 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-10-01T15:48:15.035Z,1569944895.035 [BPC1] Loaded 2019-10-01T15:48:15.035Z,1569944895.035 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-10-01T15:48:15.036Z,1569944895.036 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-10-01T15:48:15.036Z,1569944895.036 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-10-01T15:48:15.106Z,1569944895.106 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-10-01T15:48:15.107Z,1569944895.107 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-10-01T15:48:15.172Z,1569944895.172 [VerticalControl](DEBUG): Construct VerticalControl. 2019-10-01T15:48:15.259Z,1569944895.259 [VerticalControl] Loaded 2019-10-01T15:48:15.259Z,1569944895.259 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-10-01T15:48:15.260Z,1569944895.260 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-10-01T15:48:15.318Z,1569944895.318 [HorizontalControl] Loaded 2019-10-01T15:48:15.319Z,1569944895.319 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-10-01T15:48:15.319Z,1569944895.319 [SpeedControl](DEBUG): Construct SpeedControl. 2019-10-01T15:48:15.321Z,1569944895.321 [SpeedControl] Loaded 2019-10-01T15:48:15.321Z,1569944895.321 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-10-01T15:48:15.322Z,1569944895.322 [LoopControl](DEBUG): Construct LoopControl. 2019-10-01T15:48:15.322Z,1569944895.322 [LoopControl] Loaded 2019-10-01T15:48:15.323Z,1569944895.323 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-10-01T15:48:15.323Z,1569944895.323 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-10-01T15:48:15.324Z,1569944895.324 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-10-01T15:48:15.337Z,1569944895.337 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-10-01T15:48:15.337Z,1569944895.337 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-10-01T15:48:15.856Z,1569944895.856 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-10-01T15:48:15.860Z,1569944895.860 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-10-01T15:48:15.861Z,1569944895.861 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-10-01T15:48:15.867Z,1569944895.867 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-10-01T15:48:15.868Z,1569944895.868 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0 2019-10-01T15:48:15.869Z,1569944895.869 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3793 2019-10-01T15:48:15.874Z,1569944895.874 [Supervisor](INFO): Main Thread ID is 3705 2019-10-01T15:48:15.874Z,1569944895.874 [Supervisor](DEBUG): Running supervisor. 2019-10-01T15:48:15.874Z,1569944895.874 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3794 2019-10-01T15:48:15.877Z,1569944895.877 [controlThread ThreadHandler](INFO): Handler Thread ID is 3795 2019-10-01T15:48:15.877Z,1569944895.877 [controlThread](DEBUG): Initializing ControlThread 2019-10-01T15:48:15.879Z,1569944895.879 [SBIT](INFO): Initialize SBIT Component. 2019-10-01T15:48:15.879Z,1569944895.879 [SBIT](IMPORTANT): git: 2019-10-01_A 2019-10-01T15:48:15.879Z,1569944895.879 [SBIT](INFO): git hash: 45f1fece079aa3565d4a3aba33a016ea6943a305 2019-10-01T15:48:15.880Z,1569944895.880 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-10-01T15:48:15.881Z,1569944895.881 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-10-01T15:48:15.882Z,1569944895.882 [SBIT](INFO): Beginning SBIT in 52.000000 seconds. 2019-10-01T15:48:15.883Z,1569944895.883 [IBIT](INFO): Initialize IBIT Component. 2019-10-01T15:48:15.884Z,1569944895.884 [CBIT](DEBUG): Initialize CBIT Component. 2019-10-01T15:48:15.885Z,1569944895.885 [logger ThreadHandler](INFO): Handler Thread ID is 3796 2019-10-01T15:48:15.897Z,1569944895.897 [CBIT](DEBUG): Initialized mux pins. 2019-10-01T15:48:15.897Z,1569944895.897 [CBIT](DEBUG): Initializing the watchdog timer. 2019-10-01T15:48:15.906Z,1569944895.906 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3797 2019-10-01T15:48:15.906Z,1569944895.906 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-10-01T15:48:15.910Z,1569944895.910 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-10-01T15:48:15.911Z,1569944895.911 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3799 2019-10-01T15:48:15.912Z,1569944895.912 [WetLabsBB2FL](INFO): Powering down 2019-10-01T15:48:15.922Z,1569944895.922 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-10-01T15:48:15.922Z,1569944895.922 [CBIT](DEBUG): Initializing heartbeat. 2019-10-01T15:48:15.942Z,1569944895.942 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3800 2019-10-01T15:48:15.943Z,1569944895.943 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-10-01T15:48:15.958Z,1569944895.958 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3801 2019-10-01T15:48:15.968Z,1569944895.968 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3802 2019-10-01T15:48:15.971Z,1569944895.971 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-10-01T15:48:15.971Z,1569944895.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-10-01T15:48:15.971Z,1569944895.971 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-10-01T15:48:15.971Z,1569944895.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-10-01T15:48:15.971Z,1569944895.971 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-10-01T15:48:15.971Z,1569944895.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-10-01T15:48:15.972Z,1569944895.972 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-10-01T15:48:15.972Z,1569944895.972 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-10-01T15:48:15.972Z,1569944895.972 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-10-01T15:48:15.972Z,1569944895.972 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-10-01T15:48:15.972Z,1569944895.972 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-10-01T15:48:15.972Z,1569944895.972 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-10-01T15:48:15.973Z,1569944895.973 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-10-01T15:48:15.973Z,1569944895.973 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-10-01T15:48:15.973Z,1569944895.973 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-10-01T15:48:15.973Z,1569944895.973 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-10-01T15:48:15.993Z,1569944895.993 [CBIT](DEBUG): Deactivating GF circuits. 2019-10-01T15:48:15.993Z,1569944895.993 [CBIT](DEBUG): Deactivating emergency mode. 2019-10-01T15:48:16.029Z,1569944896.029 [CBIT](DEBUG): Backplane powered. 2019-10-01T15:48:16.034Z,1569944896.034 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-10-01T15:48:16.034Z,1569944896.034 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-10-01T15:48:16.034Z,1569944896.034 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-10-01T15:48:16.035Z,1569944896.035 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-10-01T15:48:16.035Z,1569944896.035 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-10-01T15:48:16.035Z,1569944896.035 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-10-01T15:48:16.037Z,1569944896.037 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-10-01T15:48:16.037Z,1569944896.037 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-10-01T15:48:16.048Z,1569944896.048 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-10-01T15:48:16.058Z,1569944896.058 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-10-01T15:48:16.059Z,1569944896.059 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-10-01T15:48:16.059Z,1569944896.059 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-10-01T15:48:16.060Z,1569944896.060 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-10-01T15:48:16.095Z,1569944896.095 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-01T15:48:16.133Z,1569944896.133 [MissionManager](DEBUG): 2019-10-01T15:48:16.134Z,1569944896.134 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-10-01T15:48:16.210Z,1569944896.210 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-10-01T15:48:16.211Z,1569944896.211 [Default:A.Wait](DEBUG): Construct Wait. 2019-10-01T15:48:16.213Z,1569944896.213 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-01T15:48:16.257Z,1569944896.257 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-10-01T15:48:16.259Z,1569944896.259 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-10-01T15:48:16.284Z,1569944896.284 [Default:E.Execute](DEBUG): Construct Execute. 2019-10-01T15:48:16.288Z,1569944896.288 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-10-01T15:48:16.297Z,1569944896.297 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-10-01T15:48:16.335Z,1569944896.335 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-10-01T15:48:16.361Z,1569944896.361 [Radio_Surface](INFO): Powering up 2019-10-01T15:48:16.394Z,1569944896.394 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar 2019-10-01T15:48:16.420Z,1569944896.420 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-10-01T15:48:16.420Z,1569944896.420 [DAT](INFO): Powering up 2019-10-01T15:48:16.420Z,1569944896.420 [DAT](DEBUG): Initializing DAT. 2019-10-01T15:48:16.474Z,1569944896.474 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-10-01T15:48:16.486Z,1569944896.486 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-10-01T15:48:16.535Z,1569944896.535 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-10-01T15:48:16.546Z,1569944896.546 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-10-01T15:48:16.547Z,1569944896.547 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-10-01T15:48:16.558Z,1569944896.558 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-10-01T15:48:16.559Z,1569944896.559 [MassServo](DEBUG): Initializing EZServoServo. 2019-10-01T15:48:16.570Z,1569944896.570 [MassServo](DEBUG): Initializing MassServo. 2019-10-01T15:48:16.570Z,1569944896.570 [RudderServo](DEBUG): Initializing EZServoServo. 2019-10-01T15:48:16.582Z,1569944896.582 [RudderServo](DEBUG): Initializing RudderServo. 2019-10-01T15:48:16.583Z,1569944896.583 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-10-01T15:48:16.590Z,1569944896.590 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-10-01T15:48:17.493Z,1569944897.493 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-10-01T15:48:17.493Z,1569944897.493 [RudderServo](FAULT): Rudder failed to initialize 2019-10-01T15:48:17.494Z,1569944897.494 [RudderServo] Communications Fault, FailCount= 1 2019-10-01T15:48:17.494Z,1569944897.494 [RudderServo](ERROR): Communications Fault 2019-10-01T15:48:17.606Z,1569944897.606 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-10-01T15:48:17.818Z,1569944897.818 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-10-01T15:48:17.818Z,1569944897.818 [RudderServo](INFO): Powering down 2019-10-01T15:48:18.480Z,1569944898.480 [RudderServo](DEBUG): Initializing EZServoServo. 2019-10-01T15:48:18.598Z,1569944898.598 [RudderServo](DEBUG): Initializing RudderServo. 2019-10-01T15:48:18.602Z,1569944898.602 [CBIT](INFO): Clearing failed state for component RudderServo 2019-10-01T15:48:18.602Z,1569944898.602 [RudderServo] No Fault, FailCount= 1 2019-10-01T15:48:19.749Z,1569944899.749 [Aanderaa_O2](INFO): Powering down 2019-10-01T15:48:26.979Z,1569944906.979 [DVL_micro](ERROR): Failed to parse: :WI,+00116,-0012,+00000,A 2019-10-01T15:48:31.427Z,1569944911.427 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004435 2019-10-01T15:48:31.827Z,1569944911.827 [DAT](INFO): setting local address to 3 2019-10-01T15:48:32.187Z,1569944912.187 [DAT](INFO): set local address to 3 2019-10-01T15:48:43.887Z,1569944923.887 [NAL9602](INFO): Powering up NAL9602 2019-10-01T15:48:54.791Z,1569944934.791 [NAL9602](INFO): NAL9602 initialized 2019-10-01T15:48:55.629Z,1569944935.629 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:48:57.222Z,1569944937.222 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T15:48:57.222Z,1569944937.222 [DVL_micro](ERROR): Failed to parse: :TS0000000,30,0000.0,1489.0I,-00072,-00016,-00385,+00000,A 2019-10-01T15:49:08.596Z,1569944948.596 [SBIT](IMPORTANT): Beginning Startup BIT 2019-10-01T15:49:08.604Z,1569944948.604 [CBIT](IMPORTANT): Beginning ground fault scan 2019-10-01T15:49:09.769Z,1569944949.769 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T15:49:09.773Z,1569944949.773 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+0.0,1489.0,000 2019-10-01T15:49:19.638Z,1569944959.638 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.026708 CHAN A1 (24V): -0.008820 CHAN A2 (12V): -0.000596 CHAN A3 (5V): -0.002834 CHAN B0 (3.3V): -0.001572 CHAN B1 (3.15aV): -0.001817 CHAN B2 (3.15bV): -0.001708 CHAN B3 (GND): -0.001969 OPEN: 0.006724 Full Scale Calc: 4.765 mA, -1.589 mA 2019-10-01T15:49:30.315Z,1569944970.315 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T15:49:35.154Z,1569944975.154 [CommandLine](IMPORTANT): got command get CBIT.abortDepth 2019-10-01T15:49:35.155Z,1569944975.155 [CommandLine](IMPORTANT): CBIT.abortDepth 295.000000 m 2019-10-01T15:49:43.391Z,1569944983.391 [CommandLine](IMPORTANT): got command get CBIT.stopDepth 2019-10-01T15:49:43.392Z,1569944983.392 [CommandLine](IMPORTANT): CBIT.stopDepth 285.000000 m 2019-10-01T15:50:01.892Z,1569945001.892 [SBIT](IMPORTANT): SBIT PASSED 2019-10-01T15:50:01.930Z,1569945001.930 [CommandLine](IMPORTANT): got command configSet list 2019-10-01T15:50:01.930Z,1569945001.930 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-10-01T15:50:01.931Z,1569945001.931 [CommandLine](IMPORTANT): No configSet variables persisted 2019-10-01T15:50:02.306Z,1569945002.306 [MissionManager](IMPORTANT): Started mission Startup 2019-10-01T15:50:02.306Z,1569945002.306 [Startup] Running Loop=1 2019-10-01T15:50:02.307Z,1569945002.307 [Startup](DEBUG): Aggregate::initialize Startup 2019-10-01T15:50:02.307Z,1569945002.307 [Startup:A.GoToSurface] Running Loop=1 2019-10-01T15:50:02.307Z,1569945002.307 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-01T15:50:02.307Z,1569945002.307 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-01T15:50:02.308Z,1569945002.308 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-01T15:50:02.308Z,1569945002.308 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-01T15:50:02.309Z,1569945002.309 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-01T15:50:02.309Z,1569945002.309 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-01T15:50:02.310Z,1569945002.310 [Startup:StartupSatComms] Running Loop=1 2019-10-01T15:50:02.311Z,1569945002.311 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-10-01T15:50:02.311Z,1569945002.311 [Startup:StartupSatComms:A] Running Loop=1 2019-10-01T15:50:02.705Z,1569945002.705 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-10-01T15:50:20.043Z,1569945020.043 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T15:50:20.044Z,1569945020.044 [DVL_micro](ERROR): Failed to parse: :BI,+00081,-00009,-00381, 2019-10-01T15:51:02.507Z,1569945062.507 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-01T15:50:02.3Z 2019-10-01T15:51:02.507Z,1569945062.507 [Startup:StartupSatComms:A] Stopped 2019-10-01T15:51:02.507Z,1569945062.507 [Startup:StartupSatComms:B] Running Loop=1 2019-10-01T15:51:02.919Z,1569945062.919 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-01T15:51:09.437Z,1569945069.437 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191001T142823/Courier0007.lzma 2019-10-01T15:51:11.443Z,1569945071.443 [DataOverHttps](INFO): Moved sent file to Logs/20191001T142823/Courier0007.lzma.bak 2019-10-01T15:51:11.443Z,1569945071.443 [DataOverHttps](INFO): SBD MOMSN=11835808 2019-10-01T15:51:16.226Z,1569945076.226 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-10-01T15:51:16.227Z,1569945076.227 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T15:51:16.236Z,1569945076.236 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T15:51:16.674Z,1569945076.674 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T15:51:16.674Z,1569945076.674 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-10-01T15:51:33.594Z,1569945093.594 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20191001T142823/Express0008.lzma 2019-10-01T15:51:35.599Z,1569945095.599 [DataOverHttps](INFO): Moved sent file to Logs/20191001T142823/Express0008.lzma.bak 2019-10-01T15:51:35.599Z,1569945095.599 [DataOverHttps](INFO): SBD MOMSN=11835810 2019-10-01T15:51:58.594Z,1569945118.594 [DataOverHttps](INFO): Sending 712 bytes from file Logs/20191001T154805/Express0001.lzma 2019-10-01T15:52:00.599Z,1569945120.599 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0001.lzma.bak 2019-10-01T15:52:00.599Z,1569945120.599 [DataOverHttps](INFO): SBD MOMSN=11835822 2019-10-01T15:52:01.887Z,1569945121.887 [Startup:StartupSatComms:B] Stopped 2019-10-01T15:52:01.887Z,1569945121.887 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-10-01T15:52:01.887Z,1569945121.887 [Startup:StartupSatComms] Stopped 2019-10-01T15:52:01.887Z,1569945121.887 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-10-01T15:52:01.888Z,1569945121.888 [Startup](INFO): Completed Startup 2019-10-01T15:52:01.888Z,1569945121.888 [MissionManager](INFO): Startup is completed. 2019-10-01T15:52:01.888Z,1569945121.888 [MissionManager](INFO): Uninitializing Mission Startup 2019-10-01T15:52:01.888Z,1569945121.888 [Startup] Stopped 2019-10-01T15:52:01.888Z,1569945121.888 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-10-01T15:52:01.888Z,1569945121.888 [Startup:A.GoToSurface] Stopped 2019-10-01T15:52:01.888Z,1569945121.888 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-01T15:52:02.298Z,1569945122.298 [MissionManager](IMPORTANT): Started mission Default 2019-10-01T15:52:02.298Z,1569945122.298 [Default] Running Loop=1 2019-10-01T15:52:02.298Z,1569945122.298 [Default](DEBUG): Aggregate::initialize Default 2019-10-01T15:52:02.299Z,1569945122.299 [Default:B.GoToSurface] Running Loop=1 2019-10-01T15:52:02.299Z,1569945122.299 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-01T15:52:02.299Z,1569945122.299 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-01T15:52:02.299Z,1569945122.299 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-01T15:52:02.299Z,1569945122.299 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-01T15:52:02.300Z,1569945122.300 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-01T15:52:02.300Z,1569945122.300 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-01T15:52:02.300Z,1569945122.300 [Default:A.Wait] Running Loop=1 2019-10-01T15:52:02.300Z,1569945122.300 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-10-01T15:52:03.076Z,1569945123.076 [DVL_micro](ERROR): only read 0 of 4 data items 2019-10-01T15:52:03.076Z,1569945123.076 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.99,+9999.99,+9999.99 2019-10-01T15:52:15.639Z,1569945135.639 [Default:A.Wait](INFO): Done Waiting. 2019-10-01T15:52:15.639Z,1569945135.639 [Default:A.Wait] Stopped 2019-10-01T15:52:15.639Z,1569945135.639 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T15:52:16.039Z,1569945136.039 [Default:CheckIn] Running Loop=1 2019-10-01T15:52:16.039Z,1569945136.039 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T15:52:16.039Z,1569945136.039 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T15:52:16.451Z,1569945136.451 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-10-01T15:52:53.275Z,1569945173.275 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T15:53:25.882Z,1569945205.882 [DVL_micro](ERROR): only read 0 of 4 data items 2019-10-01T15:53:25.882Z,1569945205.882 [DVL_micro](ERROR): Failed to parse: :RD,++9999.99,,+9999.99 2019-10-01T15:53:38.421Z,1569945218.421 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T15:53:38.422Z,1569945218.422 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.0,009.0,000 2019-10-01T15:53:57.794Z,1569945237.794 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-01T15:53:58.625Z,1569945238.625 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:02.653Z,1569945242.653 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:05.490Z,1569945245.490 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:07.501Z,1569945247.501 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:09.545Z,1569945249.545 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:12.770Z,1569945252.770 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:13.561Z,1569945253.561 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T15:54:13.561Z,1569945253.561 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2019-10-01T15:54:15.609Z,1569945255.609 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:17.213Z,1569945257.213 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-10-01T15:54:17.214Z,1569945257.214 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T15:54:17.223Z,1569945257.223 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T15:54:17.642Z,1569945257.642 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T15:54:17.642Z,1569945257.642 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-10-01T15:54:18.825Z,1569945258.825 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:21.649Z,1569945261.649 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:24.890Z,1569945264.890 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:27.709Z,1569945267.709 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:30.537Z,1569945270.537 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:32.557Z,1569945272.557 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:34.577Z,1569945274.577 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:37.809Z,1569945277.809 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:40.633Z,1569945280.633 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:43.861Z,1569945283.861 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:46.701Z,1569945286.701 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:49.526Z,1569945289.526 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:51.541Z,1569945291.541 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:53.569Z,1569945293.569 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:55.585Z,1569945295.585 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:54:57.602Z,1569945297.602 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:00.841Z,1569945300.841 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:03.665Z,1569945303.665 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:06.889Z,1569945306.889 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:09.387Z,1569945309.387 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T15:55:09.725Z,1569945309.725 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:12.958Z,1569945312.958 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:15.789Z,1569945315.789 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:18.617Z,1569945318.617 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:20.637Z,1569945320.637 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:23.865Z,1569945323.865 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:26.693Z,1569945326.693 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:29.925Z,1569945329.925 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:32.753Z,1569945332.753 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:35.647Z,1569945335.647 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T15:55:35.990Z,1569945335.990 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:38.845Z,1569945338.845 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:41.645Z,1569945341.645 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:43.665Z,1569945343.665 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:45.685Z,1569945345.685 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:48.921Z,1569945348.921 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:51.753Z,1569945351.753 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:54.973Z,1569945354.973 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:55:57.805Z,1569945357.805 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:00.649Z,1569945360.649 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:02.649Z,1569945362.649 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:04.669Z,1569945364.669 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:06.702Z,1569945366.702 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:08.721Z,1569945368.721 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:11.949Z,1569945371.949 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:14.769Z,1569945374.769 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:18.001Z,1569945378.001 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:20.829Z,1569945380.829 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:24.077Z,1569945384.077 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:26.893Z,1569945386.893 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:29.717Z,1569945389.717 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:31.737Z,1569945391.737 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:33.777Z,1569945393.777 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:36.993Z,1569945396.993 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:39.821Z,1569945399.821 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:43.049Z,1569945403.049 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:45.881Z,1569945405.881 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:49.129Z,1569945409.129 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:51.937Z,1569945411.937 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:54.765Z,1569945414.765 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:56:56.789Z,1569945416.789 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:00.021Z,1569945420.021 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:02.852Z,1569945422.852 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:06.081Z,1569945426.081 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:08.913Z,1569945428.913 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:10.962Z,1569945430.962 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-10-01T15:57:10.963Z,1569945430.963 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-10-01T15:57:10.964Z,1569945430.964 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-10-01T15:57:10.983Z,1569945430.983 [BPC1](INFO): Received data from all battery sticks. 2019-10-01T15:57:12.145Z,1569945432.145 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:14.965Z,1569945434.965 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:16.199Z,1569945436.199 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-01T15:52:16.0Z 2019-10-01T15:57:16.199Z,1569945436.199 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T15:57:16.199Z,1569945436.199 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T15:57:16.619Z,1569945436.619 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-01T15:57:16.936Z,1569945436.936 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20191001T154805/Courier0004.lzma 2019-10-01T15:57:17.797Z,1569945437.797 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:18.226Z,1569945438.226 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-10-01T15:57:18.226Z,1569945438.226 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T15:57:18.236Z,1569945438.236 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T15:57:18.647Z,1569945438.647 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T15:57:18.647Z,1569945438.647 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-10-01T15:57:18.939Z,1569945438.939 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0004.lzma.bak 2019-10-01T15:57:18.939Z,1569945438.939 [DataOverHttps](INFO): SBD MOMSN=11835849 2019-10-01T15:57:19.817Z,1569945439.817 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:21.845Z,1569945441.845 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:25.089Z,1569945445.089 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:27.893Z,1569945447.893 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:31.125Z,1569945451.125 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:33.954Z,1569945453.954 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:34.349Z,1569945454.349 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T15:57:34.350Z,1569945454.350 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+2.0,1489.0,000 2019-10-01T15:57:37.189Z,1569945457.189 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:39.709Z,1569945459.709 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20191001T154805/Express0005.lzma 2019-10-01T15:57:40.013Z,1569945460.013 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:41.715Z,1569945461.715 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0005.lzma.bak 2019-10-01T15:57:41.715Z,1569945461.715 [DataOverHttps](INFO): SBD MOMSN=11835851 2019-10-01T15:57:42.841Z,1569945462.841 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:42.880Z,1569945462.880 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T15:57:42.880Z,1569945462.880 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T15:57:42.880Z,1569945462.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T15:57:44.857Z,1569945464.857 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:48.101Z,1569945468.101 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:50.926Z,1569945470.926 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:54.173Z,1569945474.173 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:57:56.985Z,1569945476.985 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:00.213Z,1569945480.213 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:03.041Z,1569945483.041 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:05.877Z,1569945485.877 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:07.898Z,1569945487.898 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:09.499Z,1569945489.499 [DVL_micro](ERROR): Failed to parse: :7,+00162,-00425,+00000,I 2019-10-01T15:58:11.121Z,1569945491.121 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:13.949Z,1569945493.949 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:17.181Z,1569945497.181 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:20.014Z,1569945500.014 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:23.245Z,1569945503.245 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:26.069Z,1569945506.069 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:28.897Z,1569945508.897 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:30.917Z,1569945510.917 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:34.145Z,1569945514.145 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:36.985Z,1569945516.985 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:40.209Z,1569945520.209 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:43.037Z,1569945523.037 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:44.643Z,1569945524.643 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T15:58:44.644Z,1569945524.644 [DVL_micro](ERROR): Failed to parse: :TS,000000000000+21.1,0000.0,1489.0,000 2019-10-01T15:58:46.277Z,1569945526.277 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:49.097Z,1569945529.097 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:51.937Z,1569945531.937 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:53.945Z,1569945533.945 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:58:55.952Z,1569945535.952 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-10-01T15:58:55.952Z,1569945535.952 [NAL9602] Data Fault, FailCount= 1 2019-10-01T15:58:55.952Z,1569945535.952 [NAL9602](ERROR): Data Fault 2019-10-01T15:58:56.012Z,1569945536.012 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-01T15:58:56.371Z,1569945536.371 [NAL9602](INFO): Powering down 2019-10-01T15:58:57.226Z,1569945537.226 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-01T15:58:57.226Z,1569945537.226 [NAL9602] No Fault, FailCount= 1 2019-10-01T15:59:26.656Z,1569945566.656 [NAL9602](INFO): Powering up NAL9602 2019-10-01T15:59:37.564Z,1569945577.564 [NAL9602](INFO): NAL9602 initialized 2019-10-01T15:59:38.389Z,1569945578.389 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:59:40.809Z,1569945580.809 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:59:42.829Z,1569945582.829 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:59:46.061Z,1569945586.061 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:59:48.889Z,1569945588.889 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:59:52.141Z,1569945592.141 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:59:54.965Z,1569945594.965 [NAL9602](DEBUG): Fix Requested 2019-10-01T15:59:58.185Z,1569945598.185 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:01.009Z,1569945601.009 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:03.837Z,1569945603.837 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:07.077Z,1569945607.077 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:09.909Z,1569945609.909 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:13.129Z,1569945613.129 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:15.957Z,1569945615.957 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:17.579Z,1569945617.579 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-10-01T16:00:19.189Z,1569945619.189 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:19.214Z,1569945619.214 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-10-01T16:00:19.214Z,1569945619.214 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:00:19.248Z,1569945619.248 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:00:19.622Z,1569945619.622 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:00:19.622Z,1569945619.622 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-10-01T16:00:22.017Z,1569945622.017 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:24.861Z,1569945624.861 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:26.878Z,1569945626.878 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:28.885Z,1569945628.885 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:32.117Z,1569945632.117 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:34.961Z,1569945634.961 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:38.177Z,1569945638.177 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:41.010Z,1569945641.010 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:44.241Z,1569945644.241 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:47.061Z,1569945647.061 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:49.917Z,1569945649.917 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:51.916Z,1569945651.916 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:52.709Z,1569945652.709 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:00:52.709Z,1569945652.709 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,00.0,1489.0,000 2019-10-01T16:00:53.933Z,1569945653.933 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:00:57.161Z,1569945657.161 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:00.009Z,1569945660.009 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:03.233Z,1569945663.233 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:06.053Z,1569945666.053 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:09.285Z,1569945669.285 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:12.113Z,1569945672.113 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:14.953Z,1569945674.953 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:16.965Z,1569945676.965 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:20.205Z,1569945680.205 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:23.021Z,1569945683.021 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:26.253Z,1569945686.253 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:29.081Z,1569945689.081 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:32.313Z,1569945692.313 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:35.149Z,1569945695.149 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:37.980Z,1569945697.980 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:39.990Z,1569945699.990 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:40.387Z,1569945700.387 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:01:40.387Z,1569945700.387 [DVL_micro](ERROR): Failed to parse: :BI,-00058,-00196,-0029,I 2019-10-01T16:01:42.009Z,1569945702.009 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:45.249Z,1569945705.249 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:48.065Z,1569945708.065 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:51.301Z,1569945711.301 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:54.157Z,1569945714.157 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:01:57.369Z,1569945717.369 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:00.197Z,1569945720.197 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:03.025Z,1569945723.025 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:05.037Z,1569945725.037 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:08.280Z,1569945728.280 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:11.105Z,1569945731.105 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:14.333Z,1569945734.333 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:17.157Z,1569945737.157 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:20.417Z,1569945740.417 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:23.221Z,1569945743.221 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:26.041Z,1569945746.041 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:28.060Z,1569945748.060 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:02:28.060Z,1569945748.060 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.2,0000.0,1489.WI,+00069,-0402,+000I,+00069-00402,+00000+0000000000000.0000.00,000.00 2019-10-01T16:02:28.073Z,1569945748.073 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:30.093Z,1569945750.093 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:33.321Z,1569945753.321 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:36.145Z,1569945756.145 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:39.377Z,1569945759.377 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:42.213Z,1569945762.213 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:43.438Z,1569945763.438 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:02:43.438Z,1569945763.438 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:02:43.438Z,1569945763.438 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:02:43.438Z,1569945763.438 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:02:43.840Z,1569945763.840 [Default:CheckIn:D] Stopped 2019-10-01T16:02:43.840Z,1569945763.840 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:02:44.249Z,1569945764.249 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.692360 min 2019-10-01T16:02:44.249Z,1569945764.249 [Default:CheckIn:E] Stopped 2019-10-01T16:02:44.250Z,1569945764.250 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:02:44.250Z,1569945764.250 [Default:CheckIn] Stopped 2019-10-01T16:02:44.250Z,1569945764.250 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:02:44.250Z,1569945764.250 [Default:CheckIn](INFO): Running loop #2 2019-10-01T16:02:44.250Z,1569945764.250 [Default:CheckIn] Running Loop=2 2019-10-01T16:02:44.250Z,1569945764.250 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:02:44.250Z,1569945764.250 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:02:45.453Z,1569945765.453 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:48.261Z,1569945768.261 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:51.093Z,1569945771.093 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:53.125Z,1569945773.125 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:56.345Z,1569945776.345 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:02:59.173Z,1569945779.173 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:02.425Z,1569945782.425 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:05.233Z,1569945785.233 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:08.465Z,1569945788.465 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:11.293Z,1569945791.293 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:14.121Z,1569945794.121 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:16.141Z,1569945796.141 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:18.154Z,1569945798.154 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:03:18.154Z,1569945798.154 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+2.0,1489.WI,-00133,+00112,-00360,+00000,A 2019-10-01T16:03:18.165Z,1569945798.165 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:20.255Z,1569945800.255 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-10-01T16:03:20.255Z,1569945800.255 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:03:20.271Z,1569945800.271 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:03:20.643Z,1569945800.643 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:03:20.643Z,1569945800.643 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-10-01T16:03:21.397Z,1569945801.397 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:24.221Z,1569945804.221 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:27.454Z,1569945807.454 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:30.281Z,1569945810.281 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:33.521Z,1569945813.521 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:36.341Z,1569945816.341 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:39.169Z,1569945819.169 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:41.189Z,1569945821.189 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:44.417Z,1569945824.417 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:47.249Z,1569945827.249 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:50.482Z,1569945830.482 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:53.305Z,1569945833.305 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-10-01T16:03:53.317Z,1569945833.317 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:56.541Z,1569945836.541 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:03:59.369Z,1569945839.369 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:02.201Z,1569945842.201 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:04.217Z,1569945844.217 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:07.449Z,1569945847.449 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:10.285Z,1569945850.285 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:13.508Z,1569945853.508 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:04:13.508Z,1569945853.508 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2019-10-01T16:04:13.521Z,1569945853.521 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:16.337Z,1569945856.337 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:19.569Z,1569945859.569 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:22.397Z,1569945862.397 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:25.225Z,1569945865.225 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:28.465Z,1569945868.465 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:31.288Z,1569945871.288 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:34.517Z,1569945874.517 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:37.349Z,1569945877.349 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:40.573Z,1569945880.573 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:43.421Z,1569945883.421 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:46.645Z,1569945886.645 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:49.473Z,1569945889.473 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:52.293Z,1569945892.293 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:55.525Z,1569945895.525 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:04:58.377Z,1569945898.377 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:01.585Z,1569945901.585 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:04.413Z,1569945904.413 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:07.645Z,1569945907.645 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:10.473Z,1569945910.473 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:13.313Z,1569945913.313 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:15.325Z,1569945915.325 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:18.573Z,1569945918.573 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:21.393Z,1569945921.393 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:24.637Z,1569945924.637 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:27.466Z,1569945927.466 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:30.677Z,1569945930.677 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:33.529Z,1569945933.529 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:36.341Z,1569945936.341 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:38.353Z,1569945938.353 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:41.581Z,1569945941.581 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:44.413Z,1569945944.413 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:47.641Z,1569945947.641 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:50.481Z,1569945950.481 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:53.752Z,1569945953.752 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:56.555Z,1569945956.555 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:05:58.953Z,1569945958.953 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:05:58.953Z,1569945958.953 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.2,0000.0,1489.WI,+00033,+00253,-00347,+00000,A 2019-10-01T16:05:59.373Z,1569945959.373 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:01.401Z,1569945961.401 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:03.401Z,1569945963.401 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:06.641Z,1569945966.641 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:09.465Z,1569945969.465 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:12.693Z,1569945972.693 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:15.521Z,1569945975.521 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:18.773Z,1569945978.773 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:21.203Z,1569945981.203 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2019-10-01T16:06:21.203Z,1569945981.203 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:06:21.233Z,1569945981.233 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:06:21.597Z,1569945981.597 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:21.651Z,1569945981.651 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:06:21.651Z,1569945981.651 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2019-10-01T16:06:24.409Z,1569945984.409 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:26.457Z,1569945986.457 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:28.453Z,1569945988.453 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:31.689Z,1569945991.689 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:34.513Z,1569945994.513 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:37.741Z,1569945997.741 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:40.581Z,1569946000.581 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:43.802Z,1569946003.802 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:46.673Z,1569946006.673 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:49.461Z,1569946009.461 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:51.489Z,1569946011.489 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:54.709Z,1569946014.709 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:06:57.537Z,1569946017.537 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:00.773Z,1569946020.773 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:03.593Z,1569946023.593 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:06.829Z,1569946026.829 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:09.661Z,1569946029.661 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:12.493Z,1569946032.493 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:14.505Z,1569946034.505 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:16.557Z,1569946036.557 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:19.757Z,1569946039.757 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:22.585Z,1569946042.585 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:25.824Z,1569946045.824 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:28.653Z,1569946048.653 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:31.885Z,1569946051.885 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:34.705Z,1569946054.705 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:37.534Z,1569946057.534 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:39.566Z,1569946059.566 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:42.792Z,1569946062.792 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:44.431Z,1569946064.431 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-01T16:02:44.3Z 2019-10-01T16:07:44.431Z,1569946064.431 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:07:44.432Z,1569946064.432 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:07:45.617Z,1569946065.617 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:48.845Z,1569946068.845 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:51.681Z,1569946071.681 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:51.725Z,1569946071.725 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191001T154805/Courier0007.lzma 2019-10-01T16:07:53.731Z,1569946073.731 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0007.lzma.bak 2019-10-01T16:07:53.731Z,1569946073.731 [DataOverHttps](INFO): SBD MOMSN=11835863 2019-10-01T16:07:54.905Z,1569946074.905 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:07:57.737Z,1569946077.737 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:00.557Z,1569946080.557 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:02.581Z,1569946082.581 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:04.601Z,1569946084.601 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:07.833Z,1569946087.833 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:10.661Z,1569946090.661 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:13.893Z,1569946093.893 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:15.517Z,1569946095.517 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20191001T154805/Express0008.lzma 2019-10-01T16:08:16.741Z,1569946096.741 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:17.523Z,1569946097.523 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0008.lzma.bak 2019-10-01T16:08:17.523Z,1569946097.523 [DataOverHttps](INFO): SBD MOMSN=11835865 2019-10-01T16:08:18.772Z,1569946098.772 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:08:18.772Z,1569946098.772 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:08:18.772Z,1569946098.772 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:08:19.954Z,1569946099.954 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:22.785Z,1569946102.785 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:25.609Z,1569946105.609 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:27.637Z,1569946107.637 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:29.640Z,1569946109.640 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:08:29.640Z,1569946109.640 [DVL_micro](ERROR): Failed to parse: :BI,-0092,-00230,+00000,I 2019-10-01T16:08:30.861Z,1569946110.861 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:33.689Z,1569946113.689 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:36.929Z,1569946116.929 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:39.753Z,1569946119.753 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:42.981Z,1569946122.981 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:45.809Z,1569946125.809 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:48.637Z,1569946128.637 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:50.657Z,1569946130.657 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:52.258Z,1569946132.258 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:08:52.258Z,1569946132.258 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+210,1489.0,000 2019-10-01T16:08:52.685Z,1569946132.685 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:55.913Z,1569946135.913 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:08:58.737Z,1569946138.737 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:02.005Z,1569946142.005 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:04.813Z,1569946144.813 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:08.037Z,1569946148.037 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:10.857Z,1569946150.857 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:13.685Z,1569946153.685 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:15.705Z,1569946155.705 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:18.937Z,1569946158.937 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:21.765Z,1569946161.765 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:22.215Z,1569946162.215 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2019-10-01T16:09:22.215Z,1569946162.215 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:09:22.225Z,1569946162.225 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:09:22.611Z,1569946162.611 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:09:22.612Z,1569946162.612 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2019-10-01T16:09:25.025Z,1569946165.025 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:27.821Z,1569946167.821 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:30.657Z,1569946170.657 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:33.077Z,1569946173.077 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:35.905Z,1569946175.905 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:09:38.720Z,1569946178.720 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-10-01T16:09:38.720Z,1569946178.720 [NAL9602] Data Fault, FailCount= 2 2019-10-01T16:09:38.720Z,1569946178.720 [NAL9602](ERROR): Data Fault 2019-10-01T16:09:38.775Z,1569946178.775 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-01T16:09:39.124Z,1569946179.124 [NAL9602](INFO): Powering down 2019-10-01T16:09:39.979Z,1569946179.979 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-01T16:09:39.979Z,1569946179.979 [NAL9602] No Fault, FailCount= 2 2019-10-01T16:09:47.615Z,1569946187.615 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:09:47.615Z,1569946187.615 [DVL_micro](ERROR): Failed to parse: :BI,+00000,00285,+00000,I 2019-10-01T16:10:09.427Z,1569946209.427 [NAL9602](INFO): Powering up NAL9602 2019-10-01T16:10:10.236Z,1569946210.236 [DVL_micro](ERROR): only read 1 of 4 data items 2019-10-01T16:10:10.237Z,1569946210.237 [DVL_micro](ERROR): Failed to parse: :BI,+00080-00282,+00BD,+000000000000000000.00,9999.99,000.00 2019-10-01T16:10:20.332Z,1569946220.332 [NAL9602](INFO): NAL9602 initialized 2019-10-01T16:10:21.157Z,1569946221.157 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:23.577Z,1569946223.577 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:25.605Z,1569946225.605 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:28.830Z,1569946228.830 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:31.657Z,1569946231.657 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:34.896Z,1569946234.896 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:37.733Z,1569946237.733 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:40.953Z,1569946240.953 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:43.777Z,1569946243.777 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:46.605Z,1569946246.605 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:48.621Z,1569946248.621 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:51.857Z,1569946251.857 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:54.685Z,1569946254.685 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:10:57.937Z,1569946257.937 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:00.745Z,1569946260.745 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:03.977Z,1569946263.977 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:06.813Z,1569946266.813 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:09.641Z,1569946269.641 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:11.657Z,1569946271.657 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:13.673Z,1569946273.673 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:15.696Z,1569946275.696 [DVL_micro](ERROR): only read 0 of 4 data items 2019-10-01T16:11:15.696Z,1569946275.696 [DVL_micro](ERROR): Failed to parse: :BI-00106,-00225,+00BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-10-01T16:11:16.913Z,1569946276.913 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:19.737Z,1569946279.737 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:22.977Z,1569946282.977 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:25.793Z,1569946285.793 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:29.025Z,1569946289.025 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:31.861Z,1569946291.861 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:34.677Z,1569946294.677 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:37.914Z,1569946297.914 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:40.753Z,1569946300.753 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:43.973Z,1569946303.973 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:46.801Z,1569946306.801 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:50.029Z,1569946310.029 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:52.861Z,1569946312.861 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:55.709Z,1569946315.709 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:57.717Z,1569946317.717 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:11:59.729Z,1569946319.729 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:00.930Z,1569946320.930 [DVL_micro](ERROR): Failed to parse: 0000000000,35.0,+21.4,0000.0,1489.0,000 2019-10-01T16:12:01.749Z,1569946321.749 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:04.981Z,1569946324.981 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:07.809Z,1569946327.809 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:11.041Z,1569946331.041 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:13.865Z,1569946333.865 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:16.697Z,1569946336.697 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:18.713Z,1569946338.713 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:20.745Z,1569946340.745 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:22.757Z,1569946342.757 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:23.197Z,1569946343.197 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2019-10-01T16:12:23.197Z,1569946343.197 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:12:23.223Z,1569946343.223 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:12:23.551Z,1569946343.551 [DVL_micro](ERROR): Failed to parse: :WI,+00002,+00124,-00304, 2019-10-01T16:12:23.627Z,1569946343.627 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:12:23.627Z,1569946343.627 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2019-10-01T16:12:24.781Z,1569946344.781 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:28.025Z,1569946348.025 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:30.853Z,1569946350.853 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:34.065Z,1569946354.065 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:36.898Z,1569946356.898 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:40.137Z,1569946360.137 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:42.961Z,1569946362.961 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:45.785Z,1569946365.785 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:46.178Z,1569946366.178 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:12:46.179Z,1569946366.179 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+21.4,0000.0,1489.0,000 2019-10-01T16:12:47.805Z,1569946367.805 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:51.045Z,1569946371.045 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:53.870Z,1569946373.870 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:57.105Z,1569946377.105 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:12:59.934Z,1569946379.934 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:03.165Z,1569946383.165 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:05.589Z,1569946385.589 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:08.829Z,1569946388.829 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:11.661Z,1569946391.661 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:14.881Z,1569946394.881 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:17.717Z,1569946397.717 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:19.344Z,1569946399.344 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:13:19.344Z,1569946399.344 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:13:19.344Z,1569946399.344 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:13:19.344Z,1569946399.344 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:13:19.743Z,1569946399.743 [Default:CheckIn:D] Stopped 2019-10-01T16:13:19.743Z,1569946399.743 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:13:20.139Z,1569946400.139 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.290745 min 2019-10-01T16:13:20.139Z,1569946400.139 [Default:CheckIn:E] Stopped 2019-10-01T16:13:20.139Z,1569946400.139 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:13:20.139Z,1569946400.139 [Default:CheckIn] Stopped 2019-10-01T16:13:20.140Z,1569946400.140 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:13:20.140Z,1569946400.140 [Default:CheckIn](INFO): Running loop #3 2019-10-01T16:13:20.140Z,1569946400.140 [Default:CheckIn] Running Loop=3 2019-10-01T16:13:20.140Z,1569946400.140 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:13:20.140Z,1569946400.140 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:13:20.945Z,1569946400.945 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:23.777Z,1569946403.777 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:26.606Z,1569946406.606 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:29.429Z,1569946409.429 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:32.661Z,1569946412.661 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:35.486Z,1569946415.486 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:38.729Z,1569946418.729 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:41.597Z,1569946421.597 [DVL_micro](ERROR): DVL uart error: serial timeout 2019-10-01T16:13:41.597Z,1569946421.597 [DVL_micro] Communications Fault, FailCount= 1 2019-10-01T16:13:41.597Z,1569946421.597 [DVL_micro](ERROR): Communications Fault 2019-10-01T16:13:41.598Z,1569946421.598 [DVL_micro](ERROR): Failed to parse: 2019-10-01T16:13:41.609Z,1569946421.609 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:41.669Z,1569946421.669 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-01T16:13:42.006Z,1569946422.006 [DVL_micro](INFO): Powering down 2019-10-01T16:13:42.771Z,1569946422.771 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-01T16:13:42.771Z,1569946422.771 [DVL_micro] No Fault, FailCount= 1 2019-10-01T16:13:44.777Z,1569946424.777 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:47.605Z,1569946427.605 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:50.837Z,1569946430.837 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:53.681Z,1569946433.681 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:56.897Z,1569946436.897 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:13:59.725Z,1569946439.725 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:01.401Z,1569946441.401 [DVL_micro](ERROR): DVL uart error: serial timeout 2019-10-01T16:14:01.401Z,1569946441.401 [DVL_micro] Communications Fault, FailCount= 1 2019-10-01T16:14:01.401Z,1569946441.401 [DVL_micro](ERROR): Communications Fault 2019-10-01T16:14:01.402Z,1569946441.402 [DVL_micro](ERROR): Failed to parse: 2019-10-01T16:14:01.461Z,1569946441.461 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-01T16:14:01.802Z,1569946441.802 [DVL_micro](INFO): Powering down 2019-10-01T16:14:02.549Z,1569946442.549 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:02.592Z,1569946442.592 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-01T16:14:02.592Z,1569946442.592 [DVL_micro] No Fault, FailCount= 1 2019-10-01T16:14:05.792Z,1569946445.792 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:08.617Z,1569946448.617 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:11.853Z,1569946451.853 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:14.669Z,1569946454.669 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:17.510Z,1569946457.510 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:20.736Z,1569946460.736 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:23.558Z,1569946463.558 [DVL_micro](ERROR): Failed to parse: :BD,+0000000000000.00,+00000000.00,9999.99,000.00 2019-10-01T16:14:23.569Z,1569946463.569 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:26.797Z,1569946466.797 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:29.621Z,1569946469.621 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:32.853Z,1569946472.853 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:35.689Z,1569946475.689 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:38.913Z,1569946478.913 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:41.745Z,1569946481.745 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:44.973Z,1569946484.973 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:47.801Z,1569946487.801 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:51.045Z,1569946491.045 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:53.869Z,1569946493.869 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:56.689Z,1569946496.689 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:14:59.521Z,1569946499.521 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:01.537Z,1569946501.537 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:03.565Z,1569946503.565 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:05.585Z,1569946505.585 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:08.797Z,1569946508.797 [DVL_micro](ERROR): Failed to parse: :WI,-00254,-00054,-00268, 2019-10-01T16:15:08.809Z,1569946508.809 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:11.641Z,1569946511.641 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:14.865Z,1569946514.865 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:17.705Z,1569946517.705 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:20.933Z,1569946520.933 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:23.765Z,1569946523.765 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:24.203Z,1569946524.203 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2019-10-01T16:15:24.203Z,1569946524.203 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:15:24.214Z,1569946524.214 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:15:24.595Z,1569946524.595 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:15:24.595Z,1569946524.595 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2019-10-01T16:15:26.985Z,1569946526.985 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:29.821Z,1569946529.821 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:33.049Z,1569946533.049 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:35.877Z,1569946535.877 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:39.117Z,1569946539.117 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:41.949Z,1569946541.949 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:44.769Z,1569946544.769 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:48.001Z,1569946548.001 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:50.833Z,1569946550.833 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:51.626Z,1569946551.626 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:15:51.627Z,1569946551.627 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2019-10-01T16:15:53.653Z,1569946553.653 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:56.893Z,1569946556.893 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:15:59.724Z,1569946559.724 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:02.954Z,1569946562.954 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:05.777Z,1569946565.777 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:09.021Z,1569946569.021 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:11.833Z,1569946571.833 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:15.069Z,1569946575.069 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:17.896Z,1569946577.896 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:21.133Z,1569946581.133 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:23.977Z,1569946583.977 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:27.193Z,1569946587.193 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:30.017Z,1569946590.017 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:32.853Z,1569946592.853 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:35.673Z,1569946595.673 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:37.701Z,1569946597.701 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:39.720Z,1569946599.720 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:42.945Z,1569946602.945 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:45.773Z,1569946605.773 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:49.005Z,1569946609.005 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:51.857Z,1569946611.857 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:55.065Z,1569946615.065 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:16:57.893Z,1569946617.893 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:00.721Z,1569946620.721 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:03.145Z,1569946623.145 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:05.985Z,1569946625.985 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:09.206Z,1569946629.206 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:12.031Z,1569946632.031 [DVL_micro](ERROR): Failed to parse: :SA,-01.14,+01.27,035.7 2019-10-01T16:17:12.045Z,1569946632.045 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:15.261Z,1569946635.261 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:18.102Z,1569946638.102 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:20.921Z,1569946640.921 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:23.749Z,1569946643.749 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:25.769Z,1569946645.769 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:27.789Z,1569946647.789 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:31.029Z,1569946651.029 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:32.225Z,1569946652.225 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:17:32.225Z,1569946652.225 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,00.0,1489.0,000 2019-10-01T16:17:33.853Z,1569946653.853 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:37.089Z,1569946657.089 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:39.913Z,1569946659.913 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:43.141Z,1569946663.141 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:45.973Z,1569946665.973 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:48.797Z,1569946668.797 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:51.217Z,1569946671.217 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:54.049Z,1569946674.049 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:17:57.297Z,1569946677.297 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:00.113Z,1569946680.113 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:03.341Z,1569946683.341 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:06.169Z,1569946686.169 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:08.997Z,1569946688.997 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:12.237Z,1569946692.237 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:15.057Z,1569946695.057 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:17.881Z,1569946697.881 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:20.327Z,1569946700.327 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-01T16:13:20.1Z 2019-10-01T16:18:20.327Z,1569946700.327 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:18:20.327Z,1569946700.327 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:18:21.117Z,1569946701.117 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:23.945Z,1569946703.945 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:25.174Z,1569946705.174 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2019-10-01T16:18:25.174Z,1569946705.174 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:18:25.188Z,1569946705.188 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:18:25.622Z,1569946705.622 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:18:25.622Z,1569946705.622 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2019-10-01T16:18:27.182Z,1569946707.182 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:27.633Z,1569946707.633 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191001T154805/Courier0010.lzma 2019-10-01T16:18:29.639Z,1569946709.639 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0010.lzma.bak 2019-10-01T16:18:29.639Z,1569946709.639 [DataOverHttps](INFO): SBD MOMSN=11835877 2019-10-01T16:18:30.002Z,1569946710.002 [DVL_micro](ERROR): only read 1 of 4 data items 2019-10-01T16:18:30.002Z,1569946710.002 [DVL_micro](ERROR): Failed to parse: :BI,+00173-00261,+00000,I 2019-10-01T16:18:30.013Z,1569946710.013 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:33.241Z,1569946713.241 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:36.065Z,1569946716.065 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:39.297Z,1569946719.297 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:42.125Z,1569946722.125 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:45.362Z,1569946725.362 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:48.185Z,1569946728.185 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:49.420Z,1569946729.420 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20191001T154805/Express0011.lzma 2019-10-01T16:18:51.422Z,1569946731.422 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:51.431Z,1569946731.431 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0011.lzma.bak 2019-10-01T16:18:51.432Z,1569946731.432 [DataOverHttps](INFO): SBD MOMSN=11835879 2019-10-01T16:18:52.727Z,1569946732.727 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:18:52.727Z,1569946732.727 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:18:52.727Z,1569946732.727 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:18:54.245Z,1569946734.245 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:18:57.485Z,1569946737.485 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:00.308Z,1569946740.308 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:02.720Z,1569946742.720 [DVL_micro](ERROR): Failed to parse: :WI,-00066,-00270,-00214,+00000,A 2019-10-01T16:19:03.133Z,1569946743.133 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:06.369Z,1569946746.369 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:09.193Z,1569946749.193 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:12.021Z,1569946752.021 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:15.265Z,1569946755.265 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:18.085Z,1569946758.085 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:21.309Z,1569946761.309 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:24.141Z,1569946764.141 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:27.401Z,1569946767.401 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:30.221Z,1569946770.221 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:33.018Z,1569946773.018 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:19:33.019Z,1569946773.019 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+2.0,1489.WI,+00132,-00084,-00223,+00000,A 2019-10-01T16:19:33.429Z,1569946773.429 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:36.261Z,1569946776.261 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:39.089Z,1569946779.089 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:42.325Z,1569946782.325 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:45.153Z,1569946785.153 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:48.389Z,1569946788.389 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:51.213Z,1569946791.213 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:54.441Z,1569946794.441 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:19:57.269Z,1569946797.269 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:00.509Z,1569946800.509 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:03.329Z,1569946803.329 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:06.157Z,1569946806.157 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:09.393Z,1569946809.393 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:12.217Z,1569946812.217 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:15.461Z,1569946815.461 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:18.301Z,1569946818.301 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:20:21.505Z,1569946821.505 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-10-01T16:20:21.505Z,1569946821.505 [NAL9602] Data Fault, FailCount= 3 2019-10-01T16:20:21.505Z,1569946821.505 [NAL9602](ERROR): Data Fault 2019-10-01T16:20:21.535Z,1569946821.535 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-01T16:20:21.900Z,1569946821.900 [NAL9602](INFO): Powering down 2019-10-01T16:20:22.743Z,1569946822.743 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-01T16:20:22.743Z,1569946822.743 [NAL9602] No Fault, FailCount= 3 2019-10-01T16:20:52.199Z,1569946852.199 [NAL9602](INFO): Powering up NAL9602 2019-10-01T16:21:01.090Z,1569946861.090 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:21:01.090Z,1569946861.090 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.6,0000.0000 2019-10-01T16:21:03.108Z,1569946863.108 [NAL9602](INFO): NAL9602 initialized 2019-10-01T16:21:03.929Z,1569946863.929 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:06.357Z,1569946866.357 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:08.377Z,1569946868.377 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:11.605Z,1569946871.605 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:14.433Z,1569946874.433 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:17.265Z,1569946877.265 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:20.497Z,1569946880.497 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:23.321Z,1569946883.321 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:26.186Z,1569946886.186 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2019-10-01T16:21:26.186Z,1569946886.186 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:21:26.209Z,1569946886.209 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:21:26.557Z,1569946886.557 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:26.605Z,1569946886.605 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:21:26.605Z,1569946886.605 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2019-10-01T16:21:29.381Z,1569946889.381 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:32.209Z,1569946892.209 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:35.445Z,1569946895.445 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:38.269Z,1569946898.269 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:41.501Z,1569946901.501 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:44.337Z,1569946904.337 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:47.565Z,1569946907.565 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:50.397Z,1569946910.397 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:53.213Z,1569946913.213 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:55.237Z,1569946915.237 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:21:56.439Z,1569946916.439 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:21:56.439Z,1569946916.439 [DVL_micro](ERROR): Failed to parse: :BI,+00296,+00364,-0020,I 2019-10-01T16:21:57.661Z,1569946917.661 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:00.485Z,1569946920.485 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:03.729Z,1569946923.729 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:06.557Z,1569946926.557 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:09.785Z,1569946929.785 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:12.605Z,1569946932.605 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:15.441Z,1569946935.441 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:18.677Z,1569946938.677 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:21.513Z,1569946941.513 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:24.325Z,1569946944.325 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:27.557Z,1569946947.557 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:30.385Z,1569946950.385 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:33.621Z,1569946953.621 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:36.453Z,1569946956.453 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:39.681Z,1569946959.681 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:42.505Z,1569946962.505 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:45.733Z,1569946965.733 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:48.569Z,1569946968.569 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:51.805Z,1569946971.805 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:54.633Z,1569946974.633 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:22:57.857Z,1569946977.857 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:00.689Z,1569946980.689 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:03.541Z,1569946983.541 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:06.369Z,1569946986.369 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:09.601Z,1569946989.601 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:12.429Z,1569946992.429 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:15.669Z,1569946995.669 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:18.493Z,1569946998.493 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:21.737Z,1569947001.737 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:24.561Z,1569947004.561 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:27.785Z,1569947007.785 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:30.613Z,1569947010.613 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:33.841Z,1569947013.841 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:36.669Z,1569947016.669 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:39.901Z,1569947019.901 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:42.729Z,1569947022.729 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:45.969Z,1569947025.969 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:48.789Z,1569947028.789 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:51.617Z,1569947031.617 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:53.241Z,1569947033.241 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:23:53.241Z,1569947033.241 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:23:53.241Z,1569947033.241 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:23:53.241Z,1569947033.241 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:23:53.647Z,1569947033.647 [Default:CheckIn:D] Stopped 2019-10-01T16:23:53.647Z,1569947033.647 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:23:54.067Z,1569947034.067 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.855815 min 2019-10-01T16:23:54.067Z,1569947034.067 [Default:CheckIn:E] Stopped 2019-10-01T16:23:54.067Z,1569947034.067 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:23:54.067Z,1569947034.067 [Default:CheckIn] Stopped 2019-10-01T16:23:54.067Z,1569947034.067 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:23:54.068Z,1569947034.068 [Default:CheckIn](INFO): Running loop #4 2019-10-01T16:23:54.068Z,1569947034.068 [Default:CheckIn] Running Loop=4 2019-10-01T16:23:54.068Z,1569947034.068 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:23:54.068Z,1569947034.068 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:23:54.842Z,1569947034.842 [DVL_micro](ERROR): only read 0 of 4 data items 2019-10-01T16:23:54.842Z,1569947034.842 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.99,+99999.99 2019-10-01T16:23:54.853Z,1569947034.853 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:23:57.685Z,1569947037.685 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:00.909Z,1569947040.909 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:03.737Z,1569947043.737 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:06.970Z,1569947046.970 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:09.817Z,1569947049.817 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:12.629Z,1569947052.629 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:15.857Z,1569947055.857 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:18.685Z,1569947058.685 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:21.917Z,1569947061.917 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:24.765Z,1569947064.765 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:27.212Z,1569947067.212 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2019-10-01T16:24:27.212Z,1569947067.212 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T16:24:27.222Z,1569947067.222 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T16:24:27.603Z,1569947067.603 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T16:24:27.603Z,1569947067.603 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2019-10-01T16:24:27.981Z,1569947067.981 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:30.809Z,1569947070.809 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:33.633Z,1569947073.633 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:36.869Z,1569947076.869 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:24:37.283Z,1569947077.283 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162427.00,A,3648.15857,N,12147.21333,W,1.594,130.11,011019,,,A*7D 2019-10-01T16:24:37.286Z,1569947077.286 [NAL9602](INFO): GPS fix at 20191001T162427: (36.802643, -121.786889) 2019-10-01T16:24:37.360Z,1569947077.360 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:24:37.360Z,1569947077.360 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:24:47.257Z,1569947087.257 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20191001T154805/Courier0013.lzma 2019-10-01T16:24:49.263Z,1569947089.263 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0013.lzma.bak 2019-10-01T16:24:49.263Z,1569947089.263 [DataOverHttps](INFO): SBD MOMSN=11835883 2019-10-01T16:25:08.765Z,1569947108.765 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20191001T154805/Express0014.lzma 2019-10-01T16:25:09.585Z,1569947109.585 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-01T16:25:10.509Z,1569947110.509 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:25:10.509Z,1569947110.509 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.7,0000.0,1489:WI,-00186,+00146,-00266A 2019-10-01T16:25:10.771Z,1569947110.771 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0014.lzma.bak 2019-10-01T16:25:10.771Z,1569947110.771 [DataOverHttps](INFO): SBD MOMSN=11835886 2019-10-01T16:25:12.034Z,1569947112.034 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:25:12.034Z,1569947112.034 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:25:12.034Z,1569947112.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:25:53.223Z,1569947153.223 [DVL_micro](ERROR): Failed to parse: :BI,+00262,+0022,+00000,I 2019-10-01T16:27:31.415Z,1569947251.415 [DVL_micro](ERROR): Failed to parse: 00000000021.7,0000.0,1489.0,000 2019-10-01T16:29:42.332Z,1569947382.332 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:29:42.333Z,1569947382.333 [DVL_micro](ERROR): Failed to parse::BI,+0020,-00250,+00000,I 2019-10-01T16:30:12.688Z,1569947412.688 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:30:12.689Z,1569947412.689 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:30:12.689Z,1569947412.689 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:30:12.689Z,1569947412.689 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:30:13.061Z,1569947413.061 [Default:CheckIn:D] Stopped 2019-10-01T16:30:13.061Z,1569947413.061 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:30:13.468Z,1569947413.468 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.179374 min 2019-10-01T16:30:13.468Z,1569947413.468 [Default:CheckIn:E] Stopped 2019-10-01T16:30:13.468Z,1569947413.468 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:30:13.469Z,1569947413.469 [Default:CheckIn] Stopped 2019-10-01T16:30:13.469Z,1569947413.469 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:30:13.469Z,1569947413.469 [Default:CheckIn](INFO): Running loop #5 2019-10-01T16:30:13.469Z,1569947413.469 [Default:CheckIn] Running Loop=5 2019-10-01T16:30:13.469Z,1569947413.469 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:30:13.469Z,1569947413.469 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:30:15.081Z,1569947415.081 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:30:15.454Z,1569947415.454 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163004.00,A,3648.16400,N,12147.21650,W,0.039,200.74,011019,,,D*71 2019-10-01T16:30:15.456Z,1569947415.456 [NAL9602](INFO): GPS fix at 20191001T163004: (36.802733, -121.786942) 2019-10-01T16:30:15.485Z,1569947415.485 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:30:15.485Z,1569947415.485 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:30:23.505Z,1569947423.505 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191001T154805/Courier0016.lzma 2019-10-01T16:30:25.511Z,1569947425.511 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0016.lzma.bak 2019-10-01T16:30:25.511Z,1569947425.511 [DataOverHttps](INFO): SBD MOMSN=11835894 2019-10-01T16:30:34.966Z,1569947434.966 [DataOverHttps](IMPORTANT): SBD MTMSN=20191001T163024 2019-10-01T16:30:39.695Z,1569947439.695 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:30:39.695Z,1569947439.695 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:30:42.593Z,1569947442.593 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20191001T154805/Express0017.lzma 2019-10-01T16:30:42.596Z,1569947442.596 [DataOverHttps](INFO): Received command:Ibit 2019-10-01T16:30:42.658Z,1569947442.658 [CommandLine](IMPORTANT): got command ibit 2019-10-01T16:30:42.963Z,1569947442.963 [IBIT](IMPORTANT): Beginning Initiated BIT 2019-10-01T16:30:42.963Z,1569947442.963 [IBIT](IMPORTANT): Beginning control surface checks. 2019-10-01T16:30:42.966Z,1569947442.966 [CBIT](IMPORTANT): Beginning ground fault scan 2019-10-01T16:30:44.599Z,1569947444.599 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0017.lzma.bak 2019-10-01T16:30:44.599Z,1569947444.599 [DataOverHttps](INFO): SBD MOMSN=11835898 2019-10-01T16:30:54.026Z,1569947454.026 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.001620 CHAN A1 (24V): -0.010687 CHAN A2 (12V): -0.000899 CHAN A3 (5V): -0.002142 CHAN B0 (3.3V): -0.001760 CHAN B1 (3.15aV): -0.001166 CHAN B2 (3.15bV): -0.001496 CHAN B3 (GND): -0.002104 OPEN: 0.004655 Full Scale Calc: 4.765 mA, -1.589 mA 2019-10-01T16:30:54.722Z,1569947454.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:30:54.722Z,1569947454.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:31:08.005Z,1569947468.005 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:31:08.005Z,1569947468.005 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.7,089.0,000 2019-10-01T16:31:11.853Z,1569947471.853 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191001T154805/Courier0019.lzma 2019-10-01T16:31:13.859Z,1569947473.859 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0019.lzma.bak 2019-10-01T16:31:13.859Z,1569947473.859 [DataOverHttps](INFO): SBD MOMSN=11835902 2019-10-01T16:31:34.002Z,1569947494.002 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20191001T154805/Express0020.lzma 2019-10-01T16:31:36.007Z,1569947496.007 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0020.lzma.bak 2019-10-01T16:31:36.007Z,1569947496.007 [DataOverHttps](INFO): SBD MOMSN=11835904 2019-10-01T16:31:39.991Z,1569947499.991 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 2 Latitude: 36.802734 Longitude: -121.786942 2019-10-01T16:31:40.432Z,1569947500.432 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 0.000000 2019-10-01T16:31:40.432Z,1569947500.432 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2019-10-01T16:31:40.433Z,1569947500.433 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2019-10-01T16:31:40.842Z,1569947500.842 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2019-10-01T16:31:40.842Z,1569947500.842 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2019-10-01T16:31:40.843Z,1569947500.843 [IBIT](IMPORTANT): Pressure:9.860395 PSI 2019-10-01T16:31:40.843Z,1569947500.843 [IBIT](IMPORTANT): Humidity:23.995850 % 2019-10-01T16:31:41.189Z,1569947501.189 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2019-10-01T16:31:41.190Z,1569947501.190 [IBIT](IMPORTANT): buoyancyNeutral: 260.000000 cc 2019-10-01T16:31:41.190Z,1569947501.190 [IBIT](IMPORTANT): massDefault: 0.820000 cm 2019-10-01T16:31:41.190Z,1569947501.190 [IBIT](IMPORTANT): stopDepth: 285.000000 m 2019-10-01T16:31:41.191Z,1569947501.191 [IBIT](IMPORTANT): abortDepth: 295.000000 m 2019-10-01T16:31:41.191Z,1569947501.191 [IBIT](IMPORTANT): IBIT PASSED 2019-10-01T16:31:41.589Z,1569947501.589 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:31:41.589Z,1569947501.589 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:31:41.589Z,1569947501.589 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:31:50.859Z,1569947510.859 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:31:50.860Z,1569947510.860 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:32:04.972Z,1569947524.972 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:32:04.973Z,1569947524.973 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:32:13.490Z,1569947533.490 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:32:13.490Z,1569947533.490 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:32:17.002Z,1569947537.002 [CommandLine](IMPORTANT): got command failComponent 2019-10-01T16:32:17.002Z,1569947537.002 [CommandLine](IMPORTANT): Failed components: 2019-10-01T16:32:17.003Z,1569947537.003 [CommandLine](IMPORTANT): No failed Components. 2019-10-01T16:32:21.950Z,1569947541.950 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:32:21.950Z,1569947541.950 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:32:30.836Z,1569947550.836 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:32:30.837Z,1569947550.837 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:32:35.617Z,1569947555.617 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:32:35.624Z,1569947555.624 [CommandLine](IMPORTANT): platform_orientation 132.966175 arcdeg 2019-10-01T16:32:39.311Z,1569947559.311 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:32:39.311Z,1569947559.311 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:32:48.622Z,1569947568.622 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:32:48.622Z,1569947568.622 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:32:57.122Z,1569947577.122 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:32:57.123Z,1569947577.123 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:33:05.596Z,1569947585.596 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:33:05.596Z,1569947585.596 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:33:14.075Z,1569947594.075 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:33:14.075Z,1569947594.075 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:33:22.976Z,1569947602.976 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:33:22.976Z,1569947602.976 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:33:29.028Z,1569947609.028 [DVL_micro](ERROR): Failed to parse: :BI,+00141,-00100,-00207,+00000,I 2019-10-01T16:33:31.457Z,1569947611.457 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:33:31.457Z,1569947611.457 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:33:48.841Z,1569947628.841 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:33:48.842Z,1569947628.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:33:57.310Z,1569947637.310 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:33:57.311Z,1569947637.311 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:34:24.412Z,1569947664.412 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:34:24.412Z,1569947664.412 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:34:33.280Z,1569947673.280 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:34:33.280Z,1569947673.280 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:34:42.562Z,1569947682.562 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:34:42.562Z,1569947682.562 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:34:44.576Z,1569947684.576 [DVL_micro](ERROR): Failed to parse: :WI,+00309,-00028,-00260,+00000,A0309,-00028,-00260,+00000,I 2019-10-01T16:34:51.036Z,1569947691.036 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:34:51.037Z,1569947691.037 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:34:59.541Z,1569947699.541 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:34:59.541Z,1569947699.541 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:35:06.395Z,1569947706.395 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:35:06.395Z,1569947706.395 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:35:16.091Z,1569947716.091 [NAL9602](INFO): SBD MO Status=2, MOMSN=34055, MT Status=2, MTMSN=0 2019-10-01T16:35:16.091Z,1569947716.091 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-01T16:35:18.110Z,1569947718.110 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-01T16:35:27.423Z,1569947727.423 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:35:27.423Z,1569947727.423 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+21.7,0000.0,1489.0,000 2019-10-01T16:35:48.814Z,1569947748.814 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-01T16:36:00.139Z,1569947760.139 [DVL_micro](ERROR): Failed to parse: :W,-00052,-00261,+00000,A 2019-10-01T16:36:12.658Z,1569947772.658 [DVL_micro](ERROR): Failed to parse: :WI,+00070,+00001,-00225,+00000,A 2019-10-01T16:36:42.170Z,1569947802.170 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:36:42.170Z,1569947802.170 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:36:42.170Z,1569947802.170 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:36:42.170Z,1569947802.170 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:36:42.596Z,1569947802.596 [Default:CheckIn:D] Stopped 2019-10-01T16:36:42.596Z,1569947802.596 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:36:43.009Z,1569947803.009 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.671631 min 2019-10-01T16:36:43.009Z,1569947803.009 [Default:CheckIn:E] Stopped 2019-10-01T16:36:43.009Z,1569947803.009 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:36:43.009Z,1569947803.009 [Default:CheckIn] Stopped 2019-10-01T16:36:43.010Z,1569947803.010 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:36:43.010Z,1569947803.010 [Default:CheckIn](INFO): Running loop #6 2019-10-01T16:36:43.010Z,1569947803.010 [Default:CheckIn] Running Loop=6 2019-10-01T16:36:43.010Z,1569947803.010 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:36:43.010Z,1569947803.010 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:36:44.577Z,1569947804.577 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:36:44.977Z,1569947804.977 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163634.00,A,3648.26789,N,12147.14050,W,6.181,12.21,011019,,,D*40 2019-10-01T16:36:44.979Z,1569947804.979 [NAL9602](INFO): GPS fix at 20191001T163634: (36.804465, -121.785675) 2019-10-01T16:36:45.022Z,1569947805.022 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:36:45.022Z,1569947805.022 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:36:46.190Z,1569947806.190 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-10-01T16:36:52.293Z,1569947812.293 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191001T154805/Courier0022.lzma 2019-10-01T16:36:54.299Z,1569947814.299 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0022.lzma.bak 2019-10-01T16:36:54.299Z,1569947814.299 [DataOverHttps](INFO): SBD MOMSN=11835911 2019-10-01T16:36:55.517Z,1569947815.517 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:36:55.517Z,1569947815.517 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+21.7,0000.0,1489.0,000 2019-10-01T16:37:11.598Z,1569947831.598 [DataOverHttps](INFO): Sending 782 bytes from file Logs/20191001T154805/Express0023.lzma 2019-10-01T16:37:13.603Z,1569947833.603 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0023.lzma.bak 2019-10-01T16:37:13.603Z,1569947833.603 [DataOverHttps](INFO): SBD MOMSN=11835914 2019-10-01T16:37:14.888Z,1569947834.888 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:37:14.888Z,1569947834.888 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:37:14.888Z,1569947834.888 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:37:15.696Z,1569947835.696 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-01T16:37:15.773Z,1569947835.773 [NAL9602](FAULT): received: K SBDI: 2, 34055, 2, 0, 0, 0 OK 2019-10-01T16:37:15.773Z,1569947835.773 [NAL9602] Data Fault, FailCount= 4 2019-10-01T16:37:15.773Z,1569947835.773 [NAL9602](ERROR): Data Fault 2019-10-01T16:37:15.842Z,1569947835.842 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-01T16:37:16.078Z,1569947836.078 [NAL9602](INFO): Powering down 2019-10-01T16:37:16.962Z,1569947836.962 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-01T16:37:16.962Z,1569947836.962 [NAL9602] No Fault, FailCount= 4 2019-10-01T16:37:46.384Z,1569947866.384 [NAL9602](INFO): Powering up NAL9602 2019-10-01T16:37:57.287Z,1569947877.287 [NAL9602](INFO): NAL9602 initialized 2019-10-01T16:37:58.502Z,1569947878.502 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:37:58.502Z,1569947878.502 [DVL_micro](ERROR): Failed to parse: :BI,+00098,-0029,+00000,I 2019-10-01T16:38:28.411Z,1569947908.411 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-01T16:38:33.658Z,1569947913.658 [DVL_micro](ERROR): Failed to parse: :WI,-00017,-00094,-00224,+00000,00017,-00094,-00224,+00000,I 2019-10-01T16:39:03.975Z,1569947943.975 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:39:03.975Z,1569947943.975 [DVL_micro](ERROR): Failed to parse: :BI,-00008,-0253,+00BD,+0000000000000.00,+00000000.00,9999.99,000.00 2019-10-01T16:40:19.523Z,1569948019.523 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:40:19.523Z,1569948019.523 [DVL_micro](ERROR): Failed to parse: :TS0000000,.7,0000.0,1489.0,000 2019-10-01T16:41:04.812Z,1569948064.812 [DVL_micro](ERROR): Failed to parse: :SA,+02.12,+02.42,095.9 2019-10-01T16:42:15.516Z,1569948135.516 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:42:15.516Z,1569948135.516 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:42:15.516Z,1569948135.516 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:42:15.516Z,1569948135.516 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:42:15.921Z,1569948135.921 [Default:CheckIn:D] Stopped 2019-10-01T16:42:15.921Z,1569948135.921 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:42:16.328Z,1569948136.328 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.227043 min 2019-10-01T16:42:16.328Z,1569948136.328 [Default:CheckIn:E] Stopped 2019-10-01T16:42:16.328Z,1569948136.328 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:42:16.329Z,1569948136.329 [Default:CheckIn] Stopped 2019-10-01T16:42:16.329Z,1569948136.329 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:42:16.329Z,1569948136.329 [Default:CheckIn](INFO): Running loop #7 2019-10-01T16:42:16.329Z,1569948136.329 [Default:CheckIn] Running Loop=7 2019-10-01T16:42:16.329Z,1569948136.329 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:42:16.329Z,1569948136.329 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:42:17.929Z,1569948137.929 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:42:18.324Z,1569948138.324 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164206.00,A,3648.30140,N,12148.02832,W,24.512,271.57,011019,,,A*4F 2019-10-01T16:42:18.338Z,1569948138.338 [NAL9602](INFO): GPS fix at 20191001T164206: (36.805023, -121.800472) 2019-10-01T16:42:18.362Z,1569948138.362 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:42:18.362Z,1569948138.362 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:42:19.935Z,1569948139.935 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-01T16:42:25.681Z,1569948145.681 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191001T154805/Courier0025.lzma 2019-10-01T16:42:27.687Z,1569948147.687 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0025.lzma.bak 2019-10-01T16:42:27.687Z,1569948147.687 [DataOverHttps](INFO): SBD MOMSN=11835946 2019-10-01T16:42:45.005Z,1569948165.005 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20191001T154805/Express0026.lzma 2019-10-01T16:42:47.011Z,1569948167.011 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0026.lzma.bak 2019-10-01T16:42:47.012Z,1569948167.012 [DataOverHttps](INFO): SBD MOMSN=11835949 2019-10-01T16:42:48.236Z,1569948168.236 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:42:48.236Z,1569948168.236 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:42:48.236Z,1569948168.236 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:42:50.644Z,1569948170.644 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-01T16:42:53.109Z,1569948173.109 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:42:53.137Z,1569948173.137 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.7,0000.0,1489.0I,-00038,-00025,-00223,+00000,A 2019-10-01T16:43:25.809Z,1569948205.809 [DVL_micro](ERROR): Failed to parse:000000000+21.7,0000.0,1489.0,000 2019-10-01T16:43:58.546Z,1569948238.546 [DVL_micro](ERROR): only read 1 of 4 data items 2019-10-01T16:43:58.546Z,1569948238.546 [DVL_micro](ERROR): Failed to parse: :BI,-00157-00204,+000D,+0000000000000.00,+00000000.00,9999.99,000.00 2019-10-01T16:45:46.827Z,1569948346.827 [DVL_micro](ERROR): Failed to parse: :WI,-00218,-00193,-00232,+00000,A 2019-10-01T16:46:52.281Z,1569948412.281 [DVL_micro](ERROR): only read 2 of 4 data items 2019-10-01T16:46:52.281Z,1569948412.281 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,++9999.99 2019-10-01T16:47:48.850Z,1569948468.850 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:47:48.850Z,1569948468.850 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:47:48.850Z,1569948468.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:47:48.850Z,1569948468.850 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:47:49.268Z,1569948469.268 [Default:CheckIn:D] Stopped 2019-10-01T16:47:49.268Z,1569948469.268 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:47:49.673Z,1569948469.673 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.782833 min 2019-10-01T16:47:49.673Z,1569948469.673 [Default:CheckIn:E] Stopped 2019-10-01T16:47:49.673Z,1569948469.673 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:47:49.673Z,1569948469.673 [Default:CheckIn] Stopped 2019-10-01T16:47:49.673Z,1569948469.673 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:47:49.673Z,1569948469.673 [Default:CheckIn](INFO): Running loop #8 2019-10-01T16:47:49.673Z,1569948469.673 [Default:CheckIn] Running Loop=8 2019-10-01T16:47:49.674Z,1569948469.674 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:47:49.674Z,1569948469.674 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:47:51.265Z,1569948471.265 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:47:51.655Z,1569948471.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164740.00,A,3648.12447,N,12150.59059,W,24.531,262.11,011019,,,A*49 2019-10-01T16:47:51.658Z,1569948471.658 [NAL9602](INFO): GPS fix at 20191001T164740: (36.802075, -121.843176) 2019-10-01T16:47:51.681Z,1569948471.681 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:47:51.681Z,1569948471.681 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:47:59.217Z,1569948479.217 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191001T154805/Courier0028.lzma 2019-10-01T16:48:01.223Z,1569948481.223 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0028.lzma.bak 2019-10-01T16:48:01.223Z,1569948481.223 [DataOverHttps](INFO): SBD MOMSN=11835953 2019-10-01T16:48:09.040Z,1569948489.040 [NAL9602](INFO): SBD MO Status=0, MOMSN=34055, MT Status=0, MTMSN=0 2019-10-01T16:48:09.041Z,1569948489.041 [NAL9602](INFO): No messages in MT queue 2019-10-01T16:48:20.343Z,1569948500.343 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-10-01T16:48:21.293Z,1569948501.293 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20191001T154805/Express0029.lzma 2019-10-01T16:48:23.299Z,1569948503.299 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0029.lzma.bak 2019-10-01T16:48:23.299Z,1569948503.299 [DataOverHttps](INFO): SBD MOMSN=11835956 2019-10-01T16:48:24.407Z,1569948504.407 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:48:24.407Z,1569948504.407 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:48:24.407Z,1569948504.407 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:48:39.729Z,1569948519.729 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-01T16:49:15.724Z,1569948555.724 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:49:15.725Z,1569948555.725 [DVL_micro](ERROR): Failed to parse: :TS,000000,35,0000.0,1489.0,000 2019-10-01T16:49:25.823Z,1569948565.823 [DVL_micro](ERROR): Failed to parse: :WI,+00048,+00049,-00272,+00BI,+00048,+0072,+00000,I 2019-10-01T16:49:58.595Z,1569948598.595 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+21.7,0000.0,1489.0,000 2019-10-01T16:51:26.625Z,1569948686.625 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:51:26.625Z,1569948686.625 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+21.7,0000.0,1489.0,000 2019-10-01T16:51:36.715Z,1569948696.715 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:51:36.716Z,1569948696.716 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.7,089.0,000 2019-10-01T16:52:42.167Z,1569948762.167 [DVL_micro](ERROR): Failed to parse: :WI,-00316,+00004,-00293,+00000,A 2019-10-01T16:53:25.013Z,1569948805.013 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T16:53:25.013Z,1569948805.013 [Default:CheckIn:C.Wait] Stopped 2019-10-01T16:53:25.013Z,1569948805.013 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T16:53:25.013Z,1569948805.013 [Default:CheckIn:D] Running Loop=1 2019-10-01T16:53:25.424Z,1569948805.424 [Default:CheckIn:D] Stopped 2019-10-01T16:53:25.424Z,1569948805.424 [Default:CheckIn:E] Running Loop=1 2019-10-01T16:53:25.833Z,1569948805.833 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.385425 min 2019-10-01T16:53:25.833Z,1569948805.833 [Default:CheckIn:E] Stopped 2019-10-01T16:53:25.833Z,1569948805.833 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T16:53:25.833Z,1569948805.833 [Default:CheckIn] Stopped 2019-10-01T16:53:25.833Z,1569948805.833 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T16:53:25.833Z,1569948805.833 [Default:CheckIn](INFO): Running loop #9 2019-10-01T16:53:25.833Z,1569948805.833 [Default:CheckIn] Running Loop=9 2019-10-01T16:53:25.834Z,1569948805.834 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T16:53:25.834Z,1569948805.834 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T16:53:27.441Z,1569948807.441 [NAL9602](DEBUG): Fix Requested 2019-10-01T16:53:27.816Z,1569948807.816 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165316.00,A,3648.07165,N,12151.37730,W,7.076,259.30,011019,,,A*73 2019-10-01T16:53:27.818Z,1569948807.818 [NAL9602](INFO): GPS fix at 20191001T165316: (36.801194, -121.856288) 2019-10-01T16:53:27.861Z,1569948807.861 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T16:53:27.861Z,1569948807.861 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T16:53:35.025Z,1569948815.025 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191001T154805/Courier0031.lzma 2019-10-01T16:53:37.031Z,1569948817.031 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Courier0031.lzma.bak 2019-10-01T16:53:37.031Z,1569948817.031 [DataOverHttps](INFO): SBD MOMSN=11835971 2019-10-01T16:53:46.400Z,1569948826.400 [NAL9602](INFO): SBD MO Status=0, MOMSN=34056, MT Status=0, MTMSN=0 2019-10-01T16:53:46.400Z,1569948826.400 [NAL9602](INFO): No messages in MT queue 2019-10-01T16:53:54.113Z,1569948834.113 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20191001T154805/Express0032.lzma 2019-10-01T16:53:56.119Z,1569948836.119 [DataOverHttps](INFO): Moved sent file to Logs/20191001T154805/Express0032.lzma.bak 2019-10-01T16:53:56.119Z,1569948836.119 [DataOverHttps](INFO): SBD MOMSN=11835974 2019-10-01T16:53:57.349Z,1569948837.349 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T16:53:57.349Z,1569948837.349 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T16:53:57.349Z,1569948837.349 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T16:54:17.113Z,1569948857.113 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-01T16:54:45.404Z,1569948885.404 [DVL_micro](ERROR): Failed to parse: :SA,-00.30,+02.14,098.1 2019-10-01T16:55:53.231Z,1569948953.231 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:55:53.231Z,1569948953.231 [CommandLine](IMPORTANT): platform_orientation 124.511138 arcdeg 2019-10-01T16:55:59.031Z,1569948959.031 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:55:59.032Z,1569948959.032 [CommandLine](IMPORTANT): platform_orientation 110.941403 arcdeg 2019-10-01T16:56:05.674Z,1569948965.674 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:05.675Z,1569948965.675 [CommandLine](IMPORTANT): platform_orientation 96.835116 arcdeg 2019-10-01T16:56:09.290Z,1569948969.290 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:09.291Z,1569948969.291 [CommandLine](IMPORTANT): platform_orientation 86.642001 arcdeg 2019-10-01T16:56:15.591Z,1569948975.591 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:15.591Z,1569948975.591 [CommandLine](IMPORTANT): platform_orientation 65.090241 arcdeg 2019-10-01T16:56:24.903Z,1569948984.903 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:24.904Z,1569948984.904 [CommandLine](IMPORTANT): platform_orientation 32.406495 arcdeg 2019-10-01T16:56:31.053Z,1569948991.053 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:31.054Z,1569948991.054 [CommandLine](IMPORTANT): platform_orientation 3.522930 arcdeg 2019-10-01T16:56:35.629Z,1569948995.629 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:35.630Z,1569948995.630 [CommandLine](IMPORTANT): platform_orientation 339.310411 arcdeg 2019-10-01T16:56:40.325Z,1569949000.325 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:40.326Z,1569949000.326 [CommandLine](IMPORTANT): platform_orientation 313.145022 arcdeg 2019-10-01T16:56:42.490Z,1569949002.490 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:42.490Z,1569949002.490 [CommandLine](IMPORTANT): platform_orientation 301.366825 arcdeg 2019-10-01T16:56:45.195Z,1569949005.195 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:45.196Z,1569949005.196 [CommandLine](IMPORTANT): platform_orientation 283.961918 arcdeg 2019-10-01T16:56:48.849Z,1569949008.849 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:48.849Z,1569949008.849 [CommandLine](IMPORTANT): platform_orientation 264.829684 arcdeg 2019-10-01T16:56:51.174Z,1569949011.174 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:51.175Z,1569949011.175 [CommandLine](IMPORTANT): platform_orientation 250.550026 arcdeg 2019-10-01T16:56:53.502Z,1569949013.502 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:53.502Z,1569949013.502 [CommandLine](IMPORTANT): platform_orientation 236.419048 arcdeg 2019-10-01T16:56:55.435Z,1569949015.435 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:55.436Z,1569949015.436 [CommandLine](IMPORTANT): platform_orientation 228.369888 arcdeg 2019-10-01T16:56:56.293Z,1569949016.293 [DVL_micro](ERROR): Failed to parse: :.99,+9999.99,+9999.99,+9999.99 2019-10-01T16:56:59.876Z,1569949019.876 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:56:59.876Z,1569949019.876 [CommandLine](IMPORTANT): platform_orientation 205.246939 arcdeg 2019-10-01T16:57:02.741Z,1569949022.741 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:57:02.742Z,1569949022.742 [CommandLine](IMPORTANT): platform_orientation 193.616110 arcdeg 2019-10-01T16:57:05.738Z,1569949025.738 [CommandLine](IMPORTANT): got command get platform_orientation degree 2019-10-01T16:57:05.739Z,1569949025.739 [CommandLine](IMPORTANT): platform_orientation 178.471436 arcdeg 2019-10-01T16:57:14.064Z,1569949034.064 [DVL_micro](ERROR): Failed to parse: :WI,+00046,-00049,-00229,+00000,A 2019-10-01T16:57:24.163Z,1569949044.163 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T16:57:24.163Z,1569949044.163 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.8,089.0,000 2019-10-01T16:57:52.073Z,1569949072.073 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -13.00 mm (1 active estimators). 2019-10-01T16:58:08.308Z,1569949088.308 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T16:58:08.308Z,1569949088.308 [DVL_micro](ERROR): Failed to parse: :RD,+0000.30,+0000.49,+00000.53 2019-10-01T16:58:41.030Z,1569949121.030 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+18.9,0000.0,1489.0,000 2019-10-01T16:58:41.546Z,1569949121.546 [DataOverHttps](IMPORTANT): SBD MTMSN=20191001T165828 2019-10-01T16:58:49.437Z,1569949129.437 [DataOverHttps](INFO): Received command:restart logs