2019-09-20T14:46:58.090Z,1568990818.090 [Supervisor](DEBUG): Initializing supervisor. 2019-09-20T14:46:58.093Z,1568990818.093 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-09-20T14:46:58.093Z,1568990818.093 [SyncHandler](INFO): Protected caller Thread ID is 8755 2019-09-20T14:46:58.094Z,1568990818.094 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-09-20T14:46:58.094Z,1568990818.094 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-09-20T14:46:58.095Z,1568990818.095 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8756 2019-09-20T14:46:58.097Z,1568990818.097 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-09-20T14:46:58.108Z,1568990818.108 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-09-20T14:46:58.109Z,1568990818.109 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-09-20T14:46:58.109Z,1568990818.109 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8757 2019-09-20T14:46:58.110Z,1568990818.110 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-09-20T14:46:58.111Z,1568990818.111 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-09-20T14:46:58.111Z,1568990818.111 [logger ThreadHandler](INFO): Protected caller Thread ID is 8758 2019-09-20T14:46:58.113Z,1568990818.113 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-09-20T14:46:58.114Z,1568990818.114 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-09-20T14:46:58.115Z,1568990818.115 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-09-20T14:46:58.520Z,1568990818.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-09-20T14:46:58.520Z,1568990818.520 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-09-20T14:46:58.661Z,1568990818.661 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-09-20T14:46:58.662Z,1568990818.662 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-09-20T14:46:58.744Z,1568990818.744 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-09-20T14:46:58.843Z,1568990818.843 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-09-20T14:46:58.844Z,1568990818.844 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-09-20T14:46:58.939Z,1568990818.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-09-20T14:46:58.939Z,1568990818.939 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-09-20T14:46:59.311Z,1568990819.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-09-20T14:46:59.312Z,1568990819.312 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-09-20T14:46:59.413Z,1568990819.413 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-09-20T14:46:59.414Z,1568990819.414 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-09-20T14:46:59.865Z,1568990819.865 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-09-20T14:46:59.866Z,1568990819.866 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-09-20T14:47:00.064Z,1568990820.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-09-20T14:47:00.065Z,1568990820.065 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-09-20T14:47:00.365Z,1568990820.365 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-09-20T14:47:00.366Z,1568990820.366 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-09-20T14:47:00.573Z,1568990820.573 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-09-20T14:47:00.574Z,1568990820.574 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-09-20T14:47:00.714Z,1568990820.714 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-09-20T14:47:00.715Z,1568990820.715 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-09-20T14:47:01.317Z,1568990821.317 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-09-20T14:47:01.318Z,1568990821.318 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-09-20T14:47:01.661Z,1568990821.661 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-09-20T14:47:01.662Z,1568990821.662 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-09-20T14:47:01.865Z,1568990821.865 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-09-20T14:47:01.867Z,1568990821.867 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2019-09-20T14:47:01.868Z,1568990821.868 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2019-09-20T14:47:02.056Z,1568990822.056 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2019-09-20T14:47:02.222Z,1568990822.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2019-09-20T14:47:02.354Z,1568990822.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2019-09-20T14:47:02.441Z,1568990822.441 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2019-09-20T14:47:02.669Z,1568990822.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-09-20T14:47:02.670Z,1568990822.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2019-09-20T14:47:02.764Z,1568990822.764 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2019-09-20T14:47:02.873Z,1568990822.873 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2019-09-20T14:47:02.966Z,1568990822.966 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2019-09-20T14:47:03.138Z,1568990823.138 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2019-09-20T14:47:03.316Z,1568990823.316 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2019-09-20T14:47:03.502Z,1568990823.502 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-09-20T14:47:03.507Z,1568990823.507 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-09-20T14:47:03.520Z,1568990823.520 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-09-20T14:47:03.521Z,1568990823.521 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-09-20T14:47:03.586Z,1568990823.586 [VerticalControl](DEBUG): Construct VerticalControl. 2019-09-20T14:47:03.810Z,1568990823.810 [VerticalControl] Loaded 2019-09-20T14:47:03.810Z,1568990823.810 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-09-20T14:47:03.811Z,1568990823.811 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-09-20T14:47:04.048Z,1568990824.048 [HorizontalControl] Loaded 2019-09-20T14:47:04.048Z,1568990824.048 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-09-20T14:47:04.049Z,1568990824.049 [SpeedControl](DEBUG): Construct SpeedControl. 2019-09-20T14:47:04.054Z,1568990824.054 [SpeedControl] Loaded 2019-09-20T14:47:04.055Z,1568990824.055 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-09-20T14:47:04.055Z,1568990824.055 [LoopControl](DEBUG): Construct LoopControl. 2019-09-20T14:47:04.056Z,1568990824.056 [LoopControl] Loaded 2019-09-20T14:47:04.056Z,1568990824.056 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-09-20T14:47:04.057Z,1568990824.057 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-09-20T14:47:04.057Z,1568990824.057 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-09-20T14:47:04.342Z,1568990824.342 [BuoyancyServo] Loaded 2019-09-20T14:47:04.342Z,1568990824.342 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-09-20T14:47:04.359Z,1568990824.359 [ElevatorServo] Loaded 2019-09-20T14:47:04.359Z,1568990824.359 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-09-20T14:47:04.370Z,1568990824.370 [MassServo] Loaded 2019-09-20T14:47:04.370Z,1568990824.370 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-09-20T14:47:04.380Z,1568990824.380 [RudderServo] Loaded 2019-09-20T14:47:04.381Z,1568990824.381 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-09-20T14:47:04.391Z,1568990824.391 [ThrusterServo] Loaded 2019-09-20T14:47:04.392Z,1568990824.392 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-09-20T14:47:04.392Z,1568990824.392 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-09-20T14:47:04.392Z,1568990824.392 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-09-20T14:47:04.431Z,1568990824.431 [DepthRateCalculator] Loaded 2019-09-20T14:47:04.431Z,1568990824.431 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-09-20T14:47:04.436Z,1568990824.436 [PitchRateCalculator] Loaded 2019-09-20T14:47:04.437Z,1568990824.437 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-09-20T14:47:04.451Z,1568990824.451 [SpeedCalculator] Loaded 2019-09-20T14:47:04.451Z,1568990824.451 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-09-20T14:47:04.472Z,1568990824.472 [TempGradientCalculator] Loaded 2019-09-20T14:47:04.472Z,1568990824.472 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-09-20T14:47:04.477Z,1568990824.477 [YawRateCalculator] Loaded 2019-09-20T14:47:04.477Z,1568990824.477 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-09-20T14:47:04.505Z,1568990824.505 [ElevatorOffsetCalculator] Loaded 2019-09-20T14:47:04.506Z,1568990824.506 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-09-20T14:47:04.506Z,1568990824.506 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-09-20T14:47:04.506Z,1568990824.506 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-09-20T14:47:04.605Z,1568990824.605 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-09-20T14:47:04.606Z,1568990824.606 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-09-20T14:47:04.625Z,1568990824.625 [NavChart] Loaded 2019-09-20T14:47:04.626Z,1568990824.626 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-09-20T14:47:04.629Z,1568990824.629 [UniversalFixResidualReporter] Loaded 2019-09-20T14:47:04.630Z,1568990824.630 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-09-20T14:47:04.630Z,1568990824.630 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-09-20T14:47:04.631Z,1568990824.631 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-09-20T14:47:04.859Z,1568990824.859 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-09-20T14:47:04.864Z,1568990824.864 [AHRS_M2](INFO): created writer for : platform_orientation 2019-09-20T14:47:04.865Z,1568990824.865 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-09-20T14:47:04.870Z,1568990824.870 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-09-20T14:47:04.871Z,1568990824.871 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-09-20T14:47:04.876Z,1568990824.876 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-09-20T14:47:04.876Z,1568990824.876 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-09-20T14:47:04.881Z,1568990824.881 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-09-20T14:47:04.950Z,1568990824.950 [AHRS_M2] Loaded 2019-09-20T14:47:04.950Z,1568990824.950 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-09-20T14:47:05.027Z,1568990825.027 [DataOverHttps] Loaded 2019-09-20T14:47:05.027Z,1568990825.027 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-09-20T14:47:05.028Z,1568990825.028 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407F84E0 2019-09-20T14:47:05.029Z,1568990825.029 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8838 2019-09-20T14:47:05.042Z,1568990825.042 [Depth_Keller] Loaded 2019-09-20T14:47:05.042Z,1568990825.042 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-09-20T14:47:05.046Z,1568990825.046 [DropWeight] Loaded 2019-09-20T14:47:05.047Z,1568990825.047 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-09-20T14:47:05.091Z,1568990825.091 [DVL_micro] Loaded 2019-09-20T14:47:05.091Z,1568990825.091 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-09-20T14:47:05.183Z,1568990825.183 [NAL9602] Loaded 2019-09-20T14:47:05.183Z,1568990825.183 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-09-20T14:47:05.199Z,1568990825.199 [Onboard] Loaded 2019-09-20T14:47:05.199Z,1568990825.199 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-09-20T14:47:05.202Z,1568990825.202 [Radio_Surface] Loaded 2019-09-20T14:47:05.202Z,1568990825.202 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-09-20T14:47:05.203Z,1568990825.203 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408284E0 2019-09-20T14:47:05.204Z,1568990825.204 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8839 2019-09-20T14:47:05.327Z,1568990825.327 [DAT] Loaded 2019-09-20T14:47:05.327Z,1568990825.327 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-09-20T14:47:06.788Z,1568990826.788 [BPC1] Loaded 2019-09-20T14:47:06.788Z,1568990826.788 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-09-20T14:47:06.788Z,1568990826.788 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-09-20T14:47:06.789Z,1568990826.789 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-09-20T14:47:06.854Z,1568990826.854 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-09-20T14:47:06.855Z,1568990826.855 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-09-20T14:47:06.951Z,1568990826.951 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-09-20T14:47:06.951Z,1568990826.951 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-09-20T14:47:06.982Z,1568990826.982 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-09-20T14:47:06.983Z,1568990826.983 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-09-20T14:47:07.147Z,1568990827.147 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-09-20T14:47:07.152Z,1568990827.152 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-09-20T14:47:07.152Z,1568990827.152 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-09-20T14:47:07.157Z,1568990827.157 [CTD_Seabird](INFO): created writer for : depth 2019-09-20T14:47:07.157Z,1568990827.157 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-09-20T14:47:07.162Z,1568990827.162 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-09-20T14:47:07.163Z,1568990827.163 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-09-20T14:47:07.168Z,1568990827.168 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-09-20T14:47:07.169Z,1568990827.169 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-09-20T14:47:07.173Z,1568990827.173 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-09-20T14:47:07.174Z,1568990827.174 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-09-20T14:47:07.179Z,1568990827.179 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-09-20T14:47:07.180Z,1568990827.180 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-09-20T14:47:07.185Z,1568990827.185 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-09-20T14:47:07.185Z,1568990827.185 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water 2019-09-20T14:47:07.191Z,1568990827.191 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water 2019-09-20T14:47:07.191Z,1568990827.191 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq 2019-09-20T14:47:07.191Z,1568990827.191 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq 2019-09-20T14:47:07.224Z,1568990827.224 [CTD_Seabird] Loaded 2019-09-20T14:47:07.224Z,1568990827.224 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-09-20T14:47:07.225Z,1568990827.225 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409BF4E0 2019-09-20T14:47:07.225Z,1568990827.225 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8840 2019-09-20T14:47:07.240Z,1568990827.240 [PAR_Licor] Loaded 2019-09-20T14:47:07.240Z,1568990827.240 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-09-20T14:47:07.285Z,1568990827.285 [WetLabsBB2FL] Loaded 2019-09-20T14:47:07.285Z,1568990827.285 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-09-20T14:47:07.286Z,1568990827.286 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409EF4E0 2019-09-20T14:47:07.287Z,1568990827.287 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8841 2019-09-20T14:47:07.288Z,1568990827.288 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-09-20T14:47:07.288Z,1568990827.288 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-09-20T14:47:07.570Z,1568990827.570 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-09-20T14:47:07.570Z,1568990827.570 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-09-20T14:47:07.695Z,1568990827.695 [SBIT](DEBUG): Construct Startup Built In Test. 2019-09-20T14:47:07.706Z,1568990827.706 [SBIT] Loaded 2019-09-20T14:47:07.706Z,1568990827.706 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-09-20T14:47:07.707Z,1568990827.707 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-09-20T14:47:07.718Z,1568990827.718 [IBIT] Loaded 2019-09-20T14:47:07.719Z,1568990827.719 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-09-20T14:47:07.722Z,1568990827.722 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-09-20T14:47:07.856Z,1568990827.856 [CBIT] Loaded 2019-09-20T14:47:07.856Z,1568990827.856 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-09-20T14:47:07.857Z,1568990827.857 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-09-20T14:47:07.860Z,1568990827.860 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-09-20T14:47:07.861Z,1568990827.861 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-09-20T14:47:07.868Z,1568990827.868 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-09-20T14:47:07.869Z,1568990827.869 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0 2019-09-20T14:47:07.869Z,1568990827.869 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8842 2019-09-20T14:47:07.873Z,1568990827.873 [Supervisor](INFO): Main Thread ID is 8754 2019-09-20T14:47:07.874Z,1568990827.874 [Supervisor](DEBUG): Running supervisor. 2019-09-20T14:47:07.874Z,1568990827.874 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8843 2019-09-20T14:47:07.884Z,1568990827.884 [controlThread ThreadHandler](INFO): Handler Thread ID is 8844 2019-09-20T14:47:07.885Z,1568990827.885 [controlThread](DEBUG): Initializing ControlThread 2019-09-20T14:47:07.885Z,1568990827.885 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-09-20T14:47:07.887Z,1568990827.887 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-09-20T14:47:07.888Z,1568990827.888 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-09-20T14:47:07.888Z,1568990827.888 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-09-20T14:47:07.890Z,1568990827.890 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-09-20T14:47:07.890Z,1568990827.890 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-09-20T14:47:07.890Z,1568990827.890 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-09-20T14:47:07.891Z,1568990827.891 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-09-20T14:47:07.891Z,1568990827.891 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-09-20T14:47:07.892Z,1568990827.892 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-09-20T14:47:07.893Z,1568990827.893 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-09-20T14:47:07.893Z,1568990827.893 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-09-20T14:47:07.899Z,1568990827.899 [SBIT](INFO): Initialize SBIT Component. 2019-09-20T14:47:07.900Z,1568990827.900 [SBIT](IMPORTANT): git: 2019-09-12-A 2019-09-20T14:47:07.900Z,1568990827.900 [SBIT](INFO): git hash: eb701a7227645e802542eb6676257ee77fc4e0fc 2019-09-20T14:47:07.900Z,1568990827.900 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-09-20T14:47:07.901Z,1568990827.901 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-09-20T14:47:07.903Z,1568990827.903 [SBIT](INFO): Beginning SBIT in 37.000000 seconds. 2019-09-20T14:47:07.903Z,1568990827.903 [IBIT](INFO): Initialize IBIT Component. 2019-09-20T14:47:07.904Z,1568990827.904 [CBIT](DEBUG): Initialize CBIT Component. 2019-09-20T14:47:07.905Z,1568990827.905 [logger ThreadHandler](INFO): Handler Thread ID is 8845 2019-09-20T14:47:07.915Z,1568990827.915 [CBIT](DEBUG): Initialized mux pins. 2019-09-20T14:47:07.915Z,1568990827.915 [CBIT](DEBUG): Initializing the watchdog timer. 2019-09-20T14:47:07.924Z,1568990827.924 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8846 2019-09-20T14:47:07.925Z,1568990827.925 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-09-20T14:47:07.936Z,1568990827.936 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8847 2019-09-20T14:47:07.939Z,1568990827.939 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-09-20T14:47:07.939Z,1568990827.939 [CBIT](DEBUG): Initializing heartbeat. 2019-09-20T14:47:07.948Z,1568990827.948 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8848 2019-09-20T14:47:07.948Z,1568990827.948 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-09-20T14:47:07.952Z,1568990827.952 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-09-20T14:47:07.953Z,1568990827.953 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8850 2019-09-20T14:47:07.954Z,1568990827.954 [WetLabsBB2FL](INFO): Powering down 2019-09-20T14:47:07.981Z,1568990827.981 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8851 2019-09-20T14:47:07.985Z,1568990827.985 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-09-20T14:47:07.985Z,1568990827.985 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-09-20T14:47:07.985Z,1568990827.985 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-09-20T14:47:07.985Z,1568990827.985 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-09-20T14:47:07.986Z,1568990827.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-09-20T14:47:07.986Z,1568990827.986 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-09-20T14:47:07.986Z,1568990827.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-09-20T14:47:07.986Z,1568990827.986 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-09-20T14:47:07.986Z,1568990827.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-09-20T14:47:07.986Z,1568990827.986 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-09-20T14:47:07.987Z,1568990827.987 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-09-20T14:47:07.987Z,1568990827.987 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-09-20T14:47:07.987Z,1568990827.987 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-09-20T14:47:07.987Z,1568990827.987 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-09-20T14:47:07.988Z,1568990827.988 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-09-20T14:47:07.988Z,1568990827.988 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-09-20T14:47:08.011Z,1568990828.011 [CBIT](DEBUG): Deactivating GF circuits. 2019-09-20T14:47:08.011Z,1568990828.011 [CBIT](DEBUG): Deactivating emergency mode. 2019-09-20T14:47:08.047Z,1568990828.047 [CBIT](DEBUG): Backplane powered. 2019-09-20T14:47:08.048Z,1568990828.048 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-09-20T14:47:08.058Z,1568990828.058 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-20T14:47:08.080Z,1568990828.080 [MissionManager](DEBUG): 2019-09-20T14:47:08.081Z,1568990828.081 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-09-20T14:47:08.158Z,1568990828.158 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-09-20T14:47:08.159Z,1568990828.159 [Default:A.Wait](DEBUG): Construct Wait. 2019-09-20T14:47:08.161Z,1568990828.161 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-20T14:47:08.227Z,1568990828.227 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-09-20T14:47:08.230Z,1568990828.230 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-09-20T14:47:08.251Z,1568990828.251 [Default:E.Execute](DEBUG): Construct Execute. 2019-09-20T14:47:08.254Z,1568990828.254 [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-09-20T14:47:08.268Z,1568990828.268 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-09-20T14:47:08.279Z,1568990828.279 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-20T14:47:08.339Z,1568990828.339 [Radio_Surface](INFO): Powering up 2019-09-20T14:47:08.341Z,1568990828.341 [Depth_Keller](ERROR): Pressure reading out of range: 962.881653 decibar 2019-09-20T14:47:08.367Z,1568990828.367 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-20T14:47:08.367Z,1568990828.367 [DAT](INFO): Powering up 2019-09-20T14:47:08.367Z,1568990828.367 [DAT](DEBUG): Initializing DAT. 2019-09-20T14:47:08.387Z,1568990828.387 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-20T14:47:08.516Z,1568990828.516 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-09-20T14:47:08.583Z,1568990828.583 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-09-20T14:47:08.585Z,1568990828.585 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-09-20T14:47:08.586Z,1568990828.586 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-09-20T14:47:08.592Z,1568990828.592 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-09-20T14:47:08.593Z,1568990828.593 [MassServo](DEBUG): Initializing EZServoServo. 2019-09-20T14:47:08.603Z,1568990828.603 [MassServo](DEBUG): Initializing MassServo. 2019-09-20T14:47:08.605Z,1568990828.605 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-20T14:47:08.615Z,1568990828.615 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-20T14:47:08.616Z,1568990828.616 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-09-20T14:47:08.631Z,1568990828.631 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-09-20T14:47:09.479Z,1568990829.479 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-09-20T14:47:09.479Z,1568990829.479 [RudderServo](FAULT): Rudder failed to initialize 2019-09-20T14:47:09.479Z,1568990829.479 [RudderServo] Communications Fault, FailCount= 1 2019-09-20T14:47:09.480Z,1568990829.480 [RudderServo](ERROR): Communications Fault 2019-09-20T14:47:09.614Z,1568990829.614 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-09-20T14:47:09.820Z,1568990829.820 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-09-20T14:47:09.820Z,1568990829.820 [RudderServo](INFO): Powering down 2019-09-20T14:47:10.492Z,1568990830.492 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-20T14:47:10.620Z,1568990830.620 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-20T14:47:10.624Z,1568990830.624 [CBIT](INFO): Clearing failed state for component RudderServo 2019-09-20T14:47:10.624Z,1568990830.624 [RudderServo] No Fault, FailCount= 1 2019-09-20T14:47:11.963Z,1568990831.963 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:12.375Z,1568990832.375 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:13.063Z,1568990833.063 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:13.547Z,1568990833.547 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:14.083Z,1568990834.083 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:14.619Z,1568990834.619 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:15.319Z,1568990835.319 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:15.871Z,1568990835.871 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:16.279Z,1568990836.279 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:16.739Z,1568990836.739 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:17.199Z,1568990837.199 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:17.623Z,1568990837.623 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:18.052Z,1568990838.052 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:18.463Z,1568990838.463 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:18.959Z,1568990838.959 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:19.475Z,1568990839.475 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:19.903Z,1568990839.903 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:20.363Z,1568990840.363 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:20.819Z,1568990840.819 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:21.260Z,1568990841.260 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:21.261Z,1568990841.261 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-20T14:47:21.261Z,1568990841.261 [AHRS_M2] Communications Fault, FailCount= 1 2019-09-20T14:47:21.261Z,1568990841.261 [AHRS_M2](ERROR): Communications Fault 2019-09-20T14:47:21.396Z,1568990841.396 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-20T14:47:21.401Z,1568990841.401 [AHRS_M2](INFO): Powering down 2019-09-20T14:47:21.555Z,1568990841.555 [DAT](INFO): setting local address to 5 2019-09-20T14:47:21.824Z,1568990841.824 [DAT](INFO): set local address to 5 2019-09-20T14:47:22.312Z,1568990842.312 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-20T14:47:22.312Z,1568990842.312 [AHRS_M2] No Fault, FailCount= 1 2019-09-20T14:47:22.611Z,1568990842.611 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-20T14:47:23.117Z,1568990843.117 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004651 2019-09-20T14:47:26.175Z,1568990846.175 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:26.627Z,1568990846.627 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:27.123Z,1568990847.123 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:27.551Z,1568990847.551 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:27.991Z,1568990847.991 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:28.395Z,1568990848.395 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:28.815Z,1568990848.815 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:29.447Z,1568990849.447 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:29.871Z,1568990849.871 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:30.351Z,1568990850.351 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:30.771Z,1568990850.771 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:31.179Z,1568990851.179 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:31.611Z,1568990851.611 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:31.999Z,1568990851.999 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:32.435Z,1568990852.435 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:32.855Z,1568990852.855 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:33.271Z,1568990853.271 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:33.719Z,1568990853.719 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:34.111Z,1568990854.111 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:34.599Z,1568990854.599 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:35.023Z,1568990855.023 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:35.419Z,1568990855.419 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:35.425Z,1568990855.425 [NAL9602](INFO): Powering up NAL9602 2019-09-20T14:47:35.823Z,1568990855.823 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:35.823Z,1568990855.823 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-20T14:47:35.823Z,1568990855.823 [AHRS_M2] Communications Fault, FailCount= 2 2019-09-20T14:47:35.824Z,1568990855.824 [AHRS_M2](ERROR): Communications Fault 2019-09-20T14:47:35.900Z,1568990855.900 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-20T14:47:35.917Z,1568990855.917 [AHRS_M2](INFO): Powering down 2019-09-20T14:47:36.811Z,1568990856.811 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-20T14:47:36.827Z,1568990856.827 [AHRS_M2] No Fault, FailCount= 2 2019-09-20T14:47:37.115Z,1568990857.115 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-20T14:47:40.671Z,1568990860.671 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:41.083Z,1568990861.083 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:41.495Z,1568990861.495 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:41.919Z,1568990861.919 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:42.351Z,1568990862.351 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:42.751Z,1568990862.751 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:43.163Z,1568990863.163 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:43.575Z,1568990863.575 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:43.987Z,1568990863.987 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:44.415Z,1568990864.415 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:44.843Z,1568990864.843 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:45.247Z,1568990865.247 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:45.663Z,1568990865.663 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:45.721Z,1568990865.721 [SBIT](IMPORTANT): Beginning Startup BIT 2019-09-20T14:47:45.725Z,1568990865.725 [CBIT](IMPORTANT): Beginning ground fault scan 2019-09-20T14:47:46.091Z,1568990866.091 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:46.587Z,1568990866.587 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:46.593Z,1568990866.593 [NAL9602](INFO): NAL9602 initialized 2019-09-20T14:47:47.059Z,1568990867.059 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:47.779Z,1568990867.779 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:47.799Z,1568990867.799 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:47:48.339Z,1568990868.339 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:49.311Z,1568990869.311 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:49.915Z,1568990869.915 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:50.631Z,1568990870.631 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:50.631Z,1568990870.631 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-20T14:47:50.631Z,1568990870.631 [AHRS_M2] Communications Fault, FailCount= 3 2019-09-20T14:47:50.631Z,1568990870.631 [AHRS_M2](ERROR): Communications Fault 2019-09-20T14:47:50.820Z,1568990870.820 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-20T14:47:50.825Z,1568990870.825 [AHRS_M2](INFO): Powering down 2019-09-20T14:47:51.748Z,1568990871.748 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-20T14:47:51.748Z,1568990871.748 [AHRS_M2] No Fault, FailCount= 3 2019-09-20T14:47:52.035Z,1568990872.035 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-20T14:47:55.591Z,1568990875.591 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:56.103Z,1568990876.103 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:56.559Z,1568990876.559 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:57.003Z,1568990877.003 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:57.663Z,1568990877.663 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:57.764Z,1568990877.764 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.015519 CHAN A1 (24V): -0.030120 CHAN A2 (12V): -0.004948 CHAN A3 (5V): -0.002599 CHAN B0 (3.3V): -0.000719 CHAN B1 (3.15aV): -0.001359 CHAN B2 (3.15bV): -0.001655 CHAN B3 (GND): 0.000155 OPEN: 0.004653 Full Scale Calc: 4.765 mA, -1.589 mA 2019-09-20T14:47:58.116Z,1568990878.116 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:58.527Z,1568990878.527 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:58.927Z,1568990878.927 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:59.335Z,1568990879.335 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:47:59.763Z,1568990879.763 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:00.215Z,1568990880.215 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:00.651Z,1568990880.651 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:01.083Z,1568990881.083 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:01.991Z,1568990881.991 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:02.495Z,1568990882.495 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:02.995Z,1568990882.995 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:03.487Z,1568990883.487 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:03.967Z,1568990883.967 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:04.435Z,1568990884.435 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:04.919Z,1568990884.919 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:04.919Z,1568990884.919 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-20T14:48:04.919Z,1568990884.919 [AHRS_M2] Communications Fault, FailCount= 4 2019-09-20T14:48:04.919Z,1568990884.919 [AHRS_M2](ERROR): Communications Fault 2019-09-20T14:48:05.144Z,1568990885.144 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-20T14:48:05.148Z,1568990885.148 [AHRS_M2](INFO): Powering down 2019-09-20T14:48:06.108Z,1568990886.108 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-20T14:48:06.108Z,1568990886.108 [AHRS_M2] No Fault, FailCount= 4 2019-09-20T14:48:06.359Z,1568990886.359 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-20T14:48:09.903Z,1568990889.903 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:10.399Z,1568990890.399 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:10.843Z,1568990890.843 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:11.028Z,1568990891.028 [CommandLine](IMPORTANT): got command failComponent 2019-09-20T14:48:11.028Z,1568990891.028 [CommandLine](IMPORTANT): Failed components: 2019-09-20T14:48:11.028Z,1568990891.028 [CommandLine](IMPORTANT): No failed Components. 2019-09-20T14:48:11.283Z,1568990891.283 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:11.727Z,1568990891.727 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:12.171Z,1568990892.171 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:12.639Z,1568990892.639 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:13.071Z,1568990893.071 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:13.515Z,1568990893.515 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:13.939Z,1568990893.939 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:14.423Z,1568990894.423 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:14.867Z,1568990894.867 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:15.307Z,1568990895.307 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:15.727Z,1568990895.727 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:16.183Z,1568990896.183 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:16.619Z,1568990896.619 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:17.067Z,1568990897.067 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:17.539Z,1568990897.539 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:17.971Z,1568990897.971 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:18.483Z,1568990898.483 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:18.887Z,1568990898.887 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:19.295Z,1568990899.295 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:48:19.295Z,1568990899.295 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-20T14:48:19.295Z,1568990899.295 [AHRS_M2] Communications Fault, FailCount= 5 2019-09-20T14:48:19.295Z,1568990899.295 [AHRS_M2](ERROR): Communications Fault 2019-09-20T14:48:19.371Z,1568990899.371 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-20T14:48:19.371Z,1568990899.371 [CBIT](CRITICAL): Communications Fault in component: AHRS_M2 2019-09-20T14:48:19.380Z,1568990899.380 [AHRS_M2](INFO): Powering down 2019-09-20T14:48:19.501Z,1568990899.501 [CommandLine](FAULT): Scheduling is paused 2019-09-20T14:48:19.502Z,1568990899.502 [CBIT](INFO): Critical error at 20190920T144819 2019-09-20T14:48:19.502Z,1568990899.502 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-09-20T14:48:24.981Z,1568990904.981 [CommandLine](IMPORTANT): got command report mod Onboard.Pressure 2019-09-20T14:48:25.105Z,1568990905.105 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:25.491Z,1568990905.491 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:25.887Z,1568990905.887 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:26.286Z,1568990906.286 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:26.694Z,1568990906.694 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:27.693Z,1568990907.693 [Reporter](INFO): Onboard.Pressure 55153.539062 Pa 2019-09-20T14:48:28.353Z,1568990908.353 [Reporter](INFO): Onboard.Pressure 55289.218750 Pa 2019-09-20T14:48:28.521Z,1568990908.521 [Reporter](INFO): Onboard.Pressure 55333.132812 Pa 2019-09-20T14:48:29.325Z,1568990909.325 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:29.845Z,1568990909.845 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:30.173Z,1568990910.173 [Reporter](INFO): Onboard.Pressure 55210.648438 Pa 2019-09-20T14:48:30.617Z,1568990910.617 [Reporter](INFO): Onboard.Pressure 55455.480469 Pa 2019-09-20T14:48:31.066Z,1568990911.066 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:31.673Z,1568990911.673 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:32.077Z,1568990912.077 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:32.312Z,1568990912.312 [CommandLine](IMPORTANT): got command report mod Onboard.Humidity 2019-09-20T14:48:32.505Z,1568990912.505 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:32.506Z,1568990912.506 [Reporter](INFO): Onboard.Humidity 8.814552 % 2019-09-20T14:48:33.308Z,1568990913.308 [Reporter](INFO): Onboard.Pressure 55932.785156 Pa 2019-09-20T14:48:33.701Z,1568990913.701 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:34.093Z,1568990914.093 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:35.314Z,1568990915.314 [Reporter](INFO): Onboard.Pressure 55153.539062 Pa 2019-09-20T14:48:35.709Z,1568990915.709 [Reporter](INFO): Onboard.Pressure 55289.218750 Pa 2019-09-20T14:48:36.123Z,1568990916.123 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:36.513Z,1568990916.513 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:37.001Z,1568990917.001 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:37.290Z,1568990917.290 [Reporter](INFO): Onboard.Pressure 55333.132812 Pa 2019-09-20T14:48:37.733Z,1568990917.733 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:38.119Z,1568990918.119 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:38.519Z,1568990918.519 [Reporter](INFO): Onboard.Pressure 55153.539062 Pa 2019-09-20T14:48:38.910Z,1568990918.910 [Reporter](INFO): Onboard.Pressure 55289.218750 Pa 2019-09-20T14:48:39.306Z,1568990919.306 [SBIT](IMPORTANT): SBIT PASSED 2019-09-20T14:48:39.328Z,1568990919.328 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:39.403Z,1568990919.403 [CommandLine](IMPORTANT): got command configSet list 2019-09-20T14:48:39.404Z,1568990919.404 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-09-20T14:48:39.404Z,1568990919.404 [CommandLine](IMPORTANT): CBIT.gf24Offset=180 microampere; 2019-09-20T14:48:39.404Z,1568990919.404 [CommandLine](IMPORTANT): Express linearApproximation Tracking.range_to_contact 10.000000 meter; 2019-09-20T14:48:39.405Z,1568990919.405 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=270 cubic_centimeter; 2019-09-20T14:48:39.405Z,1568990919.405 [CommandLine](IMPORTANT): VerticalControl.massDefault=-4.25 millimeter; 2019-09-20T14:48:39.704Z,1568990919.704 [MissionManager](IMPORTANT): Started mission Startup 2019-09-20T14:48:39.705Z,1568990919.705 [Startup] Running Loop=1 2019-09-20T14:48:39.705Z,1568990919.705 [Startup](DEBUG): Aggregate::initialize Startup 2019-09-20T14:48:39.705Z,1568990919.705 [Startup:A.GoToSurface] Running Loop=1 2019-09-20T14:48:39.705Z,1568990919.705 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-09-20T14:48:39.706Z,1568990919.706 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-09-20T14:48:39.706Z,1568990919.706 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-09-20T14:48:39.706Z,1568990919.706 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-09-20T14:48:39.707Z,1568990919.707 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-09-20T14:48:39.707Z,1568990919.707 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-09-20T14:48:39.709Z,1568990919.709 [Startup:StartupSatComms] Running Loop=1 2019-09-20T14:48:39.709Z,1568990919.709 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-09-20T14:48:39.709Z,1568990919.709 [Startup:StartupSatComms:A] Running Loop=1 2019-09-20T14:48:39.719Z,1568990919.719 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:40.138Z,1568990920.138 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-09-20T14:48:40.160Z,1568990920.160 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:40.513Z,1568990920.513 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:41.330Z,1568990921.330 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:41.727Z,1568990921.727 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:42.131Z,1568990922.131 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:43.095Z,1568990923.095 [Reporter](INFO): Onboard.Pressure 55153.539062 Pa 2019-09-20T14:48:43.377Z,1568990923.377 [Reporter](INFO): Onboard.Pressure 55433.468750 Pa 2019-09-20T14:48:43.786Z,1568990923.786 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:44.957Z,1568990924.957 [Reporter](INFO): Onboard.Pressure 55153.539062 Pa 2019-09-20T14:48:45.061Z,1568990925.061 [CommandLine](IMPORTANT): got command failComponent 2019-09-20T14:48:45.061Z,1568990925.061 [CommandLine](IMPORTANT): Failed components: 2019-09-20T14:48:45.062Z,1568990925.062 [CommandLine](IMPORTANT): AHRS_M2: Communications Fault 2019-09-20T14:48:45.376Z,1568990925.376 [Reporter](INFO): Onboard.Pressure 55433.468750 Pa 2019-09-20T14:48:45.772Z,1568990925.772 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:46.185Z,1568990926.185 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:46.573Z,1568990926.573 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:47.384Z,1568990927.384 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:47.817Z,1568990927.817 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:48.219Z,1568990928.219 [Reporter](INFO): Onboard.Pressure 55355.074219 Pa 2019-09-20T14:48:48.606Z,1568990928.606 [Reporter](INFO): Onboard.Pressure 55477.496094 Pa 2019-09-20T14:48:49.018Z,1568990929.018 [Reporter](INFO): Onboard.Pressure 55499.503906 Pa 2019-09-20T14:48:49.620Z,1568990929.620 [CommandLine](IMPORTANT): got command report clear 2019-09-20T14:49:07.977Z,1568990947.977 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-09-20T14:49:07.977Z,1568990947.977 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-09-20T14:49:07.977Z,1568990947.977 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-20T14:49:07.988Z,1568990947.988 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-20T14:49:08.421Z,1568990948.421 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-20T14:49:08.421Z,1568990948.421 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-09-20T14:49:23.716Z,1568990963.716 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T14:49:23.716Z,1568990963.716 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.999 2019-09-20T14:49:39.897Z,1568990979.897 [Startup:StartupSatComms:A](INFO): Timed out from 2019-09-20T14:48:39.7Z 2019-09-20T14:49:39.897Z,1568990979.897 [Startup:StartupSatComms:A] Stopped 2019-09-20T14:49:39.897Z,1568990979.897 [Startup:StartupSatComms:B] Running Loop=1 2019-09-20T14:49:40.297Z,1568990980.297 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-09-20T14:49:47.471Z,1568990987.471 [DataOverHttps](INFO): Sending 111 bytes from file Logs/20190919T141655/Courier0040.lzma 2019-09-20T14:49:49.477Z,1568990989.477 [DataOverHttps](INFO): Moved sent file to Logs/20190919T141655/Courier0040.lzma.bak 2019-09-20T14:49:49.477Z,1568990989.477 [DataOverHttps](INFO): SBD MOMSN=11790466 2019-09-20T14:50:07.055Z,1568991007.055 [DataOverHttps](INFO): Sending 101 bytes from file Logs/20190920T144658/Courier0000.lzma 2019-09-20T14:50:09.061Z,1568991009.061 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0000.lzma.bak 2019-09-20T14:50:09.061Z,1568991009.061 [DataOverHttps](INFO): SBD MOMSN=11790472 2019-09-20T14:50:21.814Z,1568991021.814 [CommandLine](IMPORTANT): got command failComponent 2019-09-20T14:50:21.814Z,1568991021.814 [CommandLine](IMPORTANT): Failed components: 2019-09-20T14:50:21.814Z,1568991021.814 [CommandLine](IMPORTANT): AHRS_M2: Communications Fault 2019-09-20T14:50:27.138Z,1568991027.138 [DVL_micro](ERROR): Failed to parse: :WI,+0375,+00458,+00000,A 2019-09-20T14:50:27.680Z,1568991027.680 [DataOverHttps](INFO): Sending 629 bytes from file Logs/20190919T141655/Express0041.lzma 2019-09-20T14:50:29.685Z,1568991029.685 [DataOverHttps](INFO): Moved sent file to Logs/20190919T141655/Express0041.lzma.bak 2019-09-20T14:50:29.685Z,1568991029.685 [DataOverHttps](INFO): SBD MOMSN=11790476 2019-09-20T14:50:38.981Z,1568991038.981 [CommandLine](IMPORTANT): got command show variable par 2019-09-20T14:50:39.000Z,1568991039.000 [CommandLine](IMPORTANT): PAR_Licor.loadControl (none) 2019-09-20T14:50:39.001Z,1568991039.001 [CommandLine](IMPORTANT): PAR_Licor.ad (none) 2019-09-20T14:50:39.001Z,1568991039.001 [CommandLine](IMPORTANT): PAR_Licor.adRes (bit) 2019-09-20T14:50:39.001Z,1568991039.001 [CommandLine](IMPORTANT): PAR_Licor.adTimeout (millisecond) 2019-09-20T14:50:39.002Z,1568991039.002 [CommandLine](IMPORTANT): PAR_Licor.adVref (volt) 2019-09-20T14:50:39.010Z,1568991039.010 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup (bool) 2019-09-20T14:50:39.010Z,1568991039.010 [CommandLine](IMPORTANT): PAR_Licor.simulateHardware (bool) 2019-09-20T14:50:39.010Z,1568991039.010 [CommandLine](IMPORTANT): PAR_Licor.adcCal (microampere_per_count) 2019-09-20T14:50:39.011Z,1568991039.011 [CommandLine](IMPORTANT): PAR_Licor.darkCount (count) 2019-09-20T14:50:39.011Z,1568991039.011 [CommandLine](IMPORTANT): PAR_Licor.maxBound (micromole_per_second_per_square_meter) 2019-09-20T14:50:39.011Z,1568991039.011 [CommandLine](IMPORTANT): PAR_Licor.maxValidPitch (degree) 2019-09-20T14:50:39.012Z,1568991039.012 [CommandLine](IMPORTANT): PAR_Licor.minBound (micromole_per_second_per_square_meter) 2019-09-20T14:50:39.012Z,1568991039.012 [CommandLine](IMPORTANT): PAR_Licor.minValidPitch (degree) 2019-09-20T14:50:39.012Z,1568991039.012 [CommandLine](IMPORTANT): PAR_Licor.multiplier (micromole_per_second_per_square_meter_per_microampere) 2019-09-20T14:50:39.013Z,1568991039.013 [CommandLine](IMPORTANT): PAR_Licor.serial (none) 2019-09-20T14:50:39.153Z,1568991039.153 [CommandLine](IMPORTANT): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water (micromole_per_second_per_square_meter) 2019-09-20T14:50:39.154Z,1568991039.154 [CommandLine](IMPORTANT): PAR_Licor.adcCount (count) 2019-09-20T14:50:40.089Z,1568991040.089 [Startup:StartupSatComms:B](INFO): Timed out from 2019-09-20T14:49:39.9Z 2019-09-20T14:50:40.089Z,1568991040.089 [Startup:StartupSatComms:B] Stopped 2019-09-20T14:50:40.089Z,1568991040.089 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-09-20T14:50:40.089Z,1568991040.089 [Startup:StartupSatComms] Stopped 2019-09-20T14:50:40.089Z,1568991040.089 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-09-20T14:50:40.090Z,1568991040.090 [Startup](INFO): Completed Startup 2019-09-20T14:50:40.090Z,1568991040.090 [MissionManager](INFO): Startup is completed. 2019-09-20T14:50:40.090Z,1568991040.090 [MissionManager](INFO): Uninitializing Mission Startup 2019-09-20T14:50:40.090Z,1568991040.090 [Startup] Stopped 2019-09-20T14:50:40.090Z,1568991040.090 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-09-20T14:50:40.091Z,1568991040.091 [Startup:A.GoToSurface] Stopped 2019-09-20T14:50:40.091Z,1568991040.091 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-09-20T14:50:40.496Z,1568991040.496 [MissionManager](IMPORTANT): Started mission Default 2019-09-20T14:50:40.497Z,1568991040.497 [Default] Running Loop=1 2019-09-20T14:50:40.497Z,1568991040.497 [Default](DEBUG): Aggregate::initialize Default 2019-09-20T14:50:40.497Z,1568991040.497 [Default:B.GoToSurface] Running Loop=1 2019-09-20T14:50:40.497Z,1568991040.497 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-09-20T14:50:40.497Z,1568991040.497 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-09-20T14:50:40.498Z,1568991040.498 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-09-20T14:50:40.498Z,1568991040.498 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-09-20T14:50:40.498Z,1568991040.498 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-09-20T14:50:40.498Z,1568991040.498 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-09-20T14:50:40.499Z,1568991040.499 [Default:A.Wait] Running Loop=1 2019-09-20T14:50:40.499Z,1568991040.499 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-09-20T14:50:49.742Z,1568991049.742 [CommandLine](IMPORTANT): got command report mod PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 2019-09-20T14:50:49.850Z,1568991049.850 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.027115 umol/s/m2 2019-09-20T14:50:49.873Z,1568991049.873 [DataOverHttps](INFO): Sending 1064 bytes from file Logs/20190920T144658/Express0001.lzma 2019-09-20T14:50:50.217Z,1568991050.217 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.043469 umol/s/m2 2019-09-20T14:50:50.606Z,1568991050.606 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.022209 umol/s/m2 2019-09-20T14:50:51.003Z,1568991051.003 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.038563 umol/s/m2 2019-09-20T14:50:51.413Z,1568991051.413 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.012397 umol/s/m2 2019-09-20T14:50:51.826Z,1568991051.826 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.005856 umol/s/m2 2019-09-20T14:50:51.877Z,1568991051.877 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0001.lzma.bak 2019-09-20T14:50:51.877Z,1568991051.877 [DataOverHttps](INFO): SBD MOMSN=11790508 2019-09-20T14:50:52.218Z,1568991052.218 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.043469 umol/s/m2 2019-09-20T14:50:52.630Z,1568991052.630 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.032021 umol/s/m2 2019-09-20T14:50:53.031Z,1568991053.031 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.033657 umol/s/m2 2019-09-20T14:50:53.439Z,1568991053.439 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.002585 umol/s/m2 2019-09-20T14:50:53.847Z,1568991053.847 [Default:A.Wait](INFO): Done Waiting. 2019-09-20T14:50:53.847Z,1568991053.847 [Default:A.Wait] Stopped 2019-09-20T14:50:53.847Z,1568991053.847 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T14:50:53.857Z,1568991053.857 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.035292 umol/s/m2 2019-09-20T14:50:54.241Z,1568991054.241 [Default:CheckIn] Running Loop=1 2019-09-20T14:50:54.241Z,1568991054.241 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T14:50:54.241Z,1568991054.241 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T14:50:54.267Z,1568991054.267 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.025480 umol/s/m2 2019-09-20T14:50:54.633Z,1568991054.633 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-09-20T14:50:54.643Z,1568991054.643 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.022209 umol/s/m2 2019-09-20T14:50:55.076Z,1568991055.076 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.009126 umol/s/m2 2019-09-20T14:50:55.464Z,1568991055.464 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.002585 umol/s/m2 2019-09-20T14:50:55.882Z,1568991055.882 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.018939 umol/s/m2 2019-09-20T14:50:56.275Z,1568991056.275 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.020574 umol/s/m2 2019-09-20T14:50:56.665Z,1568991056.665 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.012397 umol/s/m2 2019-09-20T14:50:57.127Z,1568991057.127 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.030385 umol/s/m2 2019-09-20T14:50:57.501Z,1568991057.501 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.022209 umol/s/m2 2019-09-20T14:50:57.960Z,1568991057.960 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.014032 umol/s/m2 2019-09-20T14:50:58.299Z,1568991058.299 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.017303 umol/s/m2 2019-09-20T14:50:58.701Z,1568991058.701 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.000950 umol/s/m2 2019-09-20T14:50:59.114Z,1568991059.114 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 58.009274 umol/s/m2 2019-09-20T14:50:59.490Z,1568991059.490 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 2450.199951 umol/s/m2 2019-09-20T14:50:59.916Z,1568991059.916 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1883.265259 umol/s/m2 2019-09-20T14:51:00.325Z,1568991060.325 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1863.034302 umol/s/m2 2019-09-20T14:51:00.717Z,1568991060.717 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 68.668503 umol/s/m2 2019-09-20T14:51:01.108Z,1568991061.108 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1129.605957 umol/s/m2 2019-09-20T14:51:01.514Z,1568991061.514 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 2616.513672 umol/s/m2 2019-09-20T14:51:01.916Z,1568991061.916 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 511.640045 umol/s/m2 2019-09-20T14:51:02.332Z,1568991062.332 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 9.243019 umol/s/m2 2019-09-20T14:51:02.746Z,1568991062.746 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.991974 umol/s/m2 2019-09-20T14:51:03.130Z,1568991063.130 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.612572 umol/s/m2 2019-09-20T14:51:03.533Z,1568991063.533 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.449036 umol/s/m2 2019-09-20T14:51:03.943Z,1568991063.943 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.337832 umol/s/m2 2019-09-20T14:51:04.338Z,1568991064.338 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.257700 umol/s/m2 2019-09-20T14:51:04.755Z,1568991064.755 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.203733 umol/s/m2 2019-09-20T14:51:05.167Z,1568991065.167 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.180838 umol/s/m2 2019-09-20T14:51:05.555Z,1568991065.555 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.192286 umol/s/m2 2019-09-20T14:51:05.969Z,1568991065.969 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.118695 umol/s/m2 2019-09-20T14:51:06.363Z,1568991066.363 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.113789 umol/s/m2 2019-09-20T14:51:06.766Z,1568991066.766 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.100707 umol/s/m2 2019-09-20T14:51:07.171Z,1568991067.171 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.090894 umol/s/m2 2019-09-20T14:51:07.602Z,1568991067.602 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.097435 umol/s/m2 2019-09-20T14:51:07.971Z,1568991067.971 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.089259 umol/s/m2 2019-09-20T14:51:08.383Z,1568991068.383 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.076176 umol/s/m2 2019-09-20T14:51:08.798Z,1568991068.798 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.081082 umol/s/m2 2019-09-20T14:51:09.217Z,1568991069.217 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-09-20T14:51:09.217Z,1568991069.217 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-09-20T14:51:09.218Z,1568991069.218 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-20T14:51:09.288Z,1568991069.288 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-20T14:51:09.295Z,1568991069.295 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.069634 umol/s/m2 2019-09-20T14:51:09.620Z,1568991069.620 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-20T14:51:09.620Z,1568991069.620 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-09-20T14:51:09.622Z,1568991069.622 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.023844 umol/s/m2 2019-09-20T14:51:10.003Z,1568991070.003 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.053281 umol/s/m2 2019-09-20T14:51:10.487Z,1568991070.487 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.077811 umol/s/m2 2019-09-20T14:51:10.812Z,1568991070.812 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.046740 umol/s/m2 2019-09-20T14:51:11.218Z,1568991071.218 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.064729 umol/s/m2 2019-09-20T14:51:11.676Z,1568991071.676 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.040198 umol/s/m2 2019-09-20T14:51:11.821Z,1568991071.821 [CommandLine](IMPORTANT): got command report clear 2019-09-20T14:51:16.934Z,1568991076.934 [CommandLine](IMPORTANT): got command failComponent none AHRS_M2 2019-09-20T14:51:16.934Z,1568991076.934 [AHRS_M2] No Fault, FailCount= 5 2019-09-20T14:51:16.934Z,1568991076.934 [CommandLine](IMPORTANT): AHRS_M2 failureMode is No Fault 2019-09-20T14:51:17.227Z,1568991077.227 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-20T14:51:20.783Z,1568991080.783 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:21.211Z,1568991081.211 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:21.627Z,1568991081.627 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:22.043Z,1568991082.043 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:22.455Z,1568991082.455 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:22.863Z,1568991082.863 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:23.287Z,1568991083.287 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:23.699Z,1568991083.699 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:24.115Z,1568991084.115 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:24.659Z,1568991084.659 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:25.083Z,1568991085.083 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:25.599Z,1568991085.599 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:26.087Z,1568991086.087 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:26.519Z,1568991086.519 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:26.981Z,1568991086.981 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:27.380Z,1568991087.380 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:27.875Z,1568991087.875 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:28.327Z,1568991088.327 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:28.751Z,1568991088.751 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:29.179Z,1568991089.179 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:29.583Z,1568991089.583 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:29.999Z,1568991089.999 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:30.415Z,1568991090.415 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-20T14:51:30.415Z,1568991090.415 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-20T14:51:30.415Z,1568991090.415 [AHRS_M2] Communications Fault, FailCount= 6 2019-09-20T14:51:30.415Z,1568991090.415 [AHRS_M2](ERROR): Communications Fault 2019-09-20T14:51:30.512Z,1568991090.512 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-20T14:51:30.512Z,1568991090.512 [CBIT](CRITICAL): Communications Fault in component: AHRS_M2 2019-09-20T14:51:30.517Z,1568991090.517 [AHRS_M2](INFO): Powering down 2019-09-20T14:51:30.635Z,1568991090.635 [CBIT](INFO): Critical error at 20190920T145130 2019-09-20T14:52:08.899Z,1568991128.899 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T14:52:08.900Z,1568991128.900 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.7,0000.0,1489.0I,+00898,+0294,+00000,A 2019-09-20T14:52:20.615Z,1568991140.615 [CommandLine](IMPORTANT): got command failComponent 2019-09-20T14:52:20.615Z,1568991140.615 [CommandLine](IMPORTANT): Failed components: 2019-09-20T14:52:20.616Z,1568991140.616 [CommandLine](IMPORTANT): AHRS_M2: Communications Fault 2019-09-20T14:52:22.854Z,1568991142.854 [CommandLine](IMPORTANT): got command failComponent none AHRS_M2 2019-09-20T14:52:22.854Z,1568991142.854 [AHRS_M2] No Fault, FailCount= 6 2019-09-20T14:52:22.854Z,1568991142.854 [CommandLine](IMPORTANT): AHRS_M2 failureMode is No Fault 2019-09-20T14:52:23.035Z,1568991143.035 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-20T14:52:43.334Z,1568991163.334 [CommandLine](IMPORTANT): got command failComponent 2019-09-20T14:52:43.334Z,1568991163.334 [CommandLine](IMPORTANT): Failed components: 2019-09-20T14:52:43.335Z,1568991163.335 [CommandLine](IMPORTANT): No failed Components. 2019-09-20T14:52:51.489Z,1568991171.489 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-20T14:52:52.323Z,1568991172.323 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:52:53.572Z,1568991173.572 [CommandLine](IMPORTANT): got command report mod platform_orientation 2019-09-20T14:52:53.959Z,1568991173.959 [Reporter](INFO): platform_orientation 5.086243 rad 2019-09-20T14:52:54.384Z,1568991174.384 [Reporter](INFO): platform_orientation 5.086620 rad 2019-09-20T14:52:54.735Z,1568991174.735 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:52:54.780Z,1568991174.780 [Reporter](INFO): platform_orientation 5.085989 rad 2019-09-20T14:52:55.187Z,1568991175.187 [Reporter](INFO): platform_orientation 5.086109 rad 2019-09-20T14:52:55.597Z,1568991175.597 [Reporter](INFO): platform_orientation 5.085807 rad 2019-09-20T14:52:55.977Z,1568991175.977 [Reporter](INFO): platform_orientation 5.086208 rad 2019-09-20T14:52:56.384Z,1568991176.384 [Reporter](INFO): platform_orientation 5.085713 rad 2019-09-20T14:52:56.786Z,1568991176.786 [Reporter](INFO): platform_orientation 5.086315 rad 2019-09-20T14:52:57.567Z,1568991177.567 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:52:57.623Z,1568991177.623 [Reporter](INFO): platform_orientation 5.086263 rad 2019-09-20T14:52:58.073Z,1568991178.073 [Reporter](INFO): platform_orientation 5.085769 rad 2019-09-20T14:52:58.430Z,1568991178.430 [Reporter](INFO): platform_orientation 5.086167 rad 2019-09-20T14:52:58.840Z,1568991178.840 [Reporter](INFO): platform_orientation 5.085721 rad 2019-09-20T14:52:59.294Z,1568991179.294 [Reporter](INFO): platform_orientation 5.086189 rad 2019-09-20T14:52:59.659Z,1568991179.659 [Reporter](INFO): platform_orientation 5.085966 rad 2019-09-20T14:53:00.047Z,1568991180.047 [Reporter](INFO): platform_orientation 5.086457 rad 2019-09-20T14:53:00.445Z,1568991180.445 [Reporter](INFO): platform_orientation 5.086173 rad 2019-09-20T14:53:00.799Z,1568991180.799 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:00.837Z,1568991180.837 [Reporter](INFO): platform_orientation 5.086245 rad 2019-09-20T14:53:01.263Z,1568991181.263 [Reporter](INFO): platform_orientation 5.085978 rad 2019-09-20T14:53:01.654Z,1568991181.654 [Reporter](INFO): platform_orientation 5.086733 rad 2019-09-20T14:53:02.084Z,1568991182.084 [Reporter](INFO): platform_orientation 5.086382 rad 2019-09-20T14:53:02.442Z,1568991182.442 [Reporter](INFO): platform_orientation 5.086578 rad 2019-09-20T14:53:02.853Z,1568991182.853 [Reporter](INFO): platform_orientation 5.085709 rad 2019-09-20T14:53:03.263Z,1568991183.263 [Reporter](INFO): platform_orientation 5.086226 rad 2019-09-20T14:53:03.643Z,1568991183.643 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:04.067Z,1568991184.067 [Reporter](INFO): platform_orientation 5.086014 rad 2019-09-20T14:53:04.499Z,1568991184.499 [Reporter](INFO): platform_orientation 5.086173 rad 2019-09-20T14:53:04.851Z,1568991184.851 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T14:53:04.851Z,1568991184.851 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2019-09-20T14:53:04.936Z,1568991184.936 [Reporter](INFO): platform_orientation 5.086658 rad 2019-09-20T14:53:05.279Z,1568991185.279 [Reporter](INFO): platform_orientation 5.086342 rad 2019-09-20T14:53:06.130Z,1568991186.130 [Reporter](INFO): platform_orientation 5.085969 rad 2019-09-20T14:53:06.515Z,1568991186.515 [Reporter](INFO): platform_orientation 5.086303 rad 2019-09-20T14:53:06.875Z,1568991186.875 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:06.938Z,1568991186.938 [Reporter](INFO): platform_orientation 5.086563 rad 2019-09-20T14:53:07.409Z,1568991187.409 [Reporter](INFO): platform_orientation 5.086022 rad 2019-09-20T14:53:07.761Z,1568991187.761 [Reporter](INFO): platform_orientation 5.086311 rad 2019-09-20T14:53:08.132Z,1568991188.132 [Reporter](INFO): platform_orientation 5.086050 rad 2019-09-20T14:53:08.540Z,1568991188.540 [Reporter](INFO): platform_orientation 5.086275 rad 2019-09-20T14:53:08.921Z,1568991188.921 [Reporter](INFO): platform_orientation 5.086106 rad 2019-09-20T14:53:09.098Z,1568991189.098 [CommandLine](IMPORTANT): got command show best platform_orientation 2019-09-20T14:53:09.099Z,1568991189.099 [CommandLine](IMPORTANT): platform_orientation best is AHRS_M2.platform_orientation 2019-09-20T14:53:09.338Z,1568991189.338 [Reporter](INFO): platform_orientation 5.086324 rad 2019-09-20T14:53:09.703Z,1568991189.703 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:09.764Z,1568991189.764 [Reporter](INFO): platform_orientation 5.086004 rad 2019-09-20T14:53:10.135Z,1568991190.135 [Reporter](INFO): platform_orientation 5.086329 rad 2019-09-20T14:53:10.544Z,1568991190.544 [Reporter](INFO): platform_orientation 5.086158 rad 2019-09-20T14:53:10.927Z,1568991190.927 [Reporter](INFO): platform_orientation 5.086398 rad 2019-09-20T14:53:11.385Z,1568991191.385 [Reporter](INFO): platform_orientation 5.086185 rad 2019-09-20T14:53:11.776Z,1568991191.776 [Reporter](INFO): platform_orientation 5.086394 rad 2019-09-20T14:53:12.173Z,1568991192.173 [Reporter](INFO): platform_orientation 5.086060 rad 2019-09-20T14:53:12.523Z,1568991192.523 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:12.582Z,1568991192.582 [Reporter](INFO): platform_orientation 5.086351 rad 2019-09-20T14:53:13.015Z,1568991193.015 [Reporter](INFO): platform_orientation 5.086394 rad 2019-09-20T14:53:13.375Z,1568991193.375 [Reporter](INFO): platform_orientation 5.086332 rad 2019-09-20T14:53:13.778Z,1568991193.778 [Reporter](INFO): platform_orientation 5.085961 rad 2019-09-20T14:53:14.139Z,1568991194.139 [CommandLine](IMPORTANT): got command report clear 2019-09-20T14:53:14.539Z,1568991194.539 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:17.767Z,1568991197.767 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:20.599Z,1568991200.599 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:23.831Z,1568991203.831 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:26.651Z,1568991206.651 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:29.499Z,1568991209.499 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:31.511Z,1568991211.511 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:33.531Z,1568991213.531 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:36.767Z,1568991216.767 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:39.595Z,1568991219.595 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:42.831Z,1568991222.831 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:45.659Z,1568991225.659 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:48.487Z,1568991228.487 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:50.511Z,1568991230.511 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:52.527Z,1568991232.527 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:55.755Z,1568991235.755 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:53:58.599Z,1568991238.599 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:01.823Z,1568991241.823 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:04.651Z,1568991244.651 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:07.883Z,1568991247.883 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:10.324Z,1568991250.324 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-09-20T14:54:10.324Z,1568991250.324 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-20T14:54:10.334Z,1568991250.334 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-20T14:54:10.711Z,1568991250.711 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:10.776Z,1568991250.776 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-20T14:54:10.776Z,1568991250.776 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-09-20T14:54:13.531Z,1568991253.531 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:16.775Z,1568991256.775 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:19.591Z,1568991259.591 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:22.838Z,1568991262.838 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:25.654Z,1568991265.654 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:26.052Z,1568991266.052 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T14:54:26.052Z,1568991266.052 [DVL_micro](ERROR): Failed to parse: :BI,+00299,-0000,+00000,I 2019-09-20T14:54:28.495Z,1568991268.495 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:30.503Z,1568991270.503 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:32.523Z,1568991272.523 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:35.751Z,1568991275.751 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:38.595Z,1568991278.595 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:39.444Z,1568991279.444 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-09-20T14:54:39.447Z,1568991279.447 [BPC1](INFO): Received data from all battery sticks. 2019-09-20T14:54:41.815Z,1568991281.815 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:44.647Z,1568991284.647 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:47.879Z,1568991287.879 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:50.699Z,1568991290.699 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:53.531Z,1568991293.531 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:56.787Z,1568991296.787 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:54:59.607Z,1568991299.607 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:02.831Z,1568991302.831 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:05.659Z,1568991305.659 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:08.487Z,1568991308.487 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:10.507Z,1568991310.507 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:12.527Z,1568991312.527 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:15.759Z,1568991315.759 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:18.583Z,1568991318.583 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:21.827Z,1568991321.827 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:24.643Z,1568991324.643 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:27.875Z,1568991327.875 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:30.719Z,1568991330.719 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:33.555Z,1568991333.555 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:36.787Z,1568991336.787 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:39.627Z,1568991339.627 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:42.847Z,1568991342.847 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:45.671Z,1568991345.671 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:48.503Z,1568991348.503 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:50.535Z,1568991350.535 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:53.767Z,1568991353.767 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:54.610Z,1568991354.610 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-09-20T14:50:54.2Z 2019-09-20T14:55:54.611Z,1568991354.611 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T14:55:54.611Z,1568991354.611 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T14:55:55.002Z,1568991355.002 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-09-20T14:55:56.579Z,1568991356.579 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:55:59.851Z,1568991359.851 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:02.655Z,1568991362.655 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:03.035Z,1568991363.035 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20190920T144658/Courier0004.lzma 2019-09-20T14:56:05.041Z,1568991365.041 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0004.lzma.bak 2019-09-20T14:56:05.041Z,1568991365.041 [DataOverHttps](INFO): SBD MOMSN=11790546 2019-09-20T14:56:05.883Z,1568991365.883 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:08.711Z,1568991368.711 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:11.531Z,1568991371.531 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:14.766Z,1568991374.766 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:17.604Z,1568991377.604 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:20.421Z,1568991380.421 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+9999.99 2019-09-20T14:56:20.823Z,1568991380.823 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:23.651Z,1568991383.651 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:23.744Z,1568991383.744 [DataOverHttps](INFO): Sending 798 bytes from file Logs/20190920T144658/Express0005.lzma 2019-09-20T14:56:25.749Z,1568991385.749 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0005.lzma.bak 2019-09-20T14:56:25.749Z,1568991385.749 [DataOverHttps](INFO): SBD MOMSN=11790549 2019-09-20T14:56:26.483Z,1568991386.483 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:28.503Z,1568991388.503 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:28.545Z,1568991388.545 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T14:56:28.545Z,1568991388.545 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T14:56:28.545Z,1568991388.545 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T14:56:30.539Z,1568991390.539 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:33.751Z,1568991393.751 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:36.583Z,1568991396.583 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:39.811Z,1568991399.811 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:42.643Z,1568991402.643 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:45.891Z,1568991405.891 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:48.704Z,1568991408.704 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:51.539Z,1568991411.539 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:54.763Z,1568991414.763 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:56:57.590Z,1568991417.590 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:00.827Z,1568991420.827 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:03.663Z,1568991423.663 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:06.479Z,1568991426.479 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:08.511Z,1568991428.511 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:10.515Z,1568991430.515 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:11.380Z,1568991431.380 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-09-20T14:57:11.380Z,1568991431.380 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-20T14:57:11.392Z,1568991431.392 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-20T14:57:11.754Z,1568991431.754 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-20T14:57:11.754Z,1568991431.754 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-09-20T14:57:13.755Z,1568991433.755 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:16.579Z,1568991436.579 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:19.819Z,1568991439.819 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:22.643Z,1568991442.643 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:25.871Z,1568991445.871 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:28.695Z,1568991448.695 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:31.547Z,1568991451.547 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:34.758Z,1568991454.758 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:37.591Z,1568991457.591 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:40.827Z,1568991460.827 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:43.647Z,1568991463.647 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:46.487Z,1568991466.487 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:57:48.484Z,1568991468.484 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-09-20T14:57:48.485Z,1568991468.485 [NAL9602] Data Fault, FailCount= 1 2019-09-20T14:57:48.485Z,1568991468.485 [NAL9602](ERROR): Data Fault 2019-09-20T14:57:48.545Z,1568991468.545 [CBIT](ERROR): Data Fault in component: NAL9602 2019-09-20T14:57:48.881Z,1568991468.881 [NAL9602](INFO): Powering down 2019-09-20T14:57:49.736Z,1568991469.736 [CBIT](INFO): Clearing failed state for component NAL9602 2019-09-20T14:57:49.736Z,1568991469.736 [NAL9602] No Fault, FailCount= 1 2019-09-20T14:58:19.181Z,1568991499.181 [NAL9602](INFO): Powering up NAL9602 2019-09-20T14:58:20.001Z,1568991500.001 [DVL_micro](ERROR): only read 0 of 4 data items 2019-09-20T14:58:20.001Z,1568991500.001 [DVL_micro](ERROR): Failed to parse: :BI-00447+00000,I 2019-09-20T14:58:30.107Z,1568991510.107 [NAL9602](INFO): NAL9602 initialized 2019-09-20T14:58:30.923Z,1568991510.923 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:33.339Z,1568991513.339 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:36.567Z,1568991516.567 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:39.395Z,1568991519.395 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:40.203Z,1568991520.203 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T14:58:40.203Z,1568991520.203 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.8,0000.0,1489.0I,+00052,-00193,+00554,+00000,A 2019-09-20T14:58:42.651Z,1568991522.651 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:45.459Z,1568991525.459 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:48.295Z,1568991528.295 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:51.523Z,1568991531.523 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:54.347Z,1568991534.347 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:58:57.579Z,1568991537.579 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:00.419Z,1568991540.419 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:03.639Z,1568991543.639 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:06.467Z,1568991546.467 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:09.295Z,1568991549.295 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:12.527Z,1568991552.527 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:15.355Z,1568991555.355 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:18.583Z,1568991558.583 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:21.411Z,1568991561.411 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:24.243Z,1568991564.243 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:27.481Z,1568991567.481 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:30.311Z,1568991570.311 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:33.547Z,1568991573.547 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:36.371Z,1568991576.371 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:39.599Z,1568991579.599 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:42.432Z,1568991582.432 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:45.263Z,1568991585.263 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:48.491Z,1568991588.491 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:51.331Z,1568991591.331 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:54.551Z,1568991594.551 [NAL9602](DEBUG): Fix Requested 2019-09-20T14:59:57.378Z,1568991597.378 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:00.611Z,1568991600.611 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:03.443Z,1568991603.443 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:06.267Z,1568991606.267 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:09.495Z,1568991609.495 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:12.327Z,1568991612.327 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:12.360Z,1568991612.360 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-09-20T15:00:12.360Z,1568991612.360 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-20T15:00:12.370Z,1568991612.370 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-20T15:00:12.771Z,1568991612.771 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-20T15:00:12.771Z,1568991612.771 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-09-20T15:00:15.151Z,1568991615.151 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:16.766Z,1568991616.766 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:00:16.766Z,1568991616.766 [DVL_micro](ERROR): Failed to parse: :BI,+00084,+00050,+00527,+00BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-09-20T15:00:18.390Z,1568991618.390 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:21.215Z,1568991621.215 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:24.455Z,1568991624.455 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:27.271Z,1568991627.271 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:30.103Z,1568991630.103 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:32.135Z,1568991632.135 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:35.351Z,1568991635.351 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:38.183Z,1568991638.183 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:39.805Z,1568991639.805 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:00:39.805Z,1568991639.805 [DVL_micro](ERROR): Failed to parse: :TS,00000000000,+20.9,000.0,000 2019-09-20T15:00:41.415Z,1568991641.415 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:44.247Z,1568991644.247 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:47.095Z,1568991647.095 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:49.495Z,1568991649.495 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:52.327Z,1568991652.327 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:55.555Z,1568991655.555 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:00:58.379Z,1568991658.379 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:01.615Z,1568991661.615 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:04.441Z,1568991664.441 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:07.271Z,1568991667.271 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:10.107Z,1568991670.107 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:13.331Z,1568991673.331 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:16.159Z,1568991676.159 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:19.387Z,1568991679.387 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:22.218Z,1568991682.218 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:25.503Z,1568991685.503 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:28.303Z,1568991688.303 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:29.153Z,1568991689.153 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:01:29.153Z,1568991689.153 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:01:29.153Z,1568991689.153 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:01:29.154Z,1568991689.154 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:01:29.565Z,1568991689.565 [Default:CheckIn:D] Stopped 2019-09-20T15:01:29.565Z,1568991689.565 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:01:29.957Z,1568991689.957 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.817800 min 2019-09-20T15:01:29.957Z,1568991689.957 [Default:CheckIn:E] Stopped 2019-09-20T15:01:29.957Z,1568991689.957 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:01:29.957Z,1568991689.957 [Default:CheckIn] Stopped 2019-09-20T15:01:29.957Z,1568991689.957 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:01:29.957Z,1568991689.957 [Default:CheckIn](INFO): Running loop #2 2019-09-20T15:01:29.957Z,1568991689.957 [Default:CheckIn] Running Loop=2 2019-09-20T15:01:29.958Z,1568991689.958 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:01:29.958Z,1568991689.958 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:01:31.527Z,1568991691.527 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:34.351Z,1568991694.351 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:37.591Z,1568991697.591 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:40.443Z,1568991700.443 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:43.647Z,1568991703.647 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:46.475Z,1568991706.475 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:49.299Z,1568991709.299 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:52.535Z,1568991712.535 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:55.361Z,1568991715.361 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:58.196Z,1568991718.196 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:01:58.585Z,1568991718.585 [DVL_micro](ERROR): only read 1 of 4 data items 2019-09-20T15:01:58.586Z,1568991718.586 [DVL_micro](ERROR): Failed to parse: :BI,+00042+00536,+0:BD,+0000+0000000000000.00,000.00 2019-09-20T15:02:01.423Z,1568991721.423 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:04.247Z,1568991724.247 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:07.479Z,1568991727.479 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:10.323Z,1568991730.323 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:13.556Z,1568991733.556 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:16.387Z,1568991736.387 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:19.199Z,1568991739.199 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:22.431Z,1568991742.431 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:25.259Z,1568991745.259 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:28.491Z,1568991748.491 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:31.323Z,1568991751.323 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:34.557Z,1568991754.557 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:37.383Z,1568991757.383 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:40.203Z,1568991760.203 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:43.435Z,1568991763.435 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:46.270Z,1568991766.270 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:49.502Z,1568991769.502 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:52.327Z,1568991772.327 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:55.559Z,1568991775.559 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:02:58.387Z,1568991778.387 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:01.215Z,1568991781.215 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:04.468Z,1568991784.468 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:07.275Z,1568991787.275 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:10.506Z,1568991790.506 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:13.339Z,1568991793.339 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:13.380Z,1568991793.380 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2019-09-20T15:03:13.380Z,1568991793.380 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-20T15:03:13.394Z,1568991793.394 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-20T15:03:13.800Z,1568991793.800 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-20T15:03:13.801Z,1568991793.801 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2019-09-20T15:03:16.567Z,1568991796.567 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:19.395Z,1568991799.395 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:22.243Z,1568991802.243 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:25.455Z,1568991805.455 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:28.283Z,1568991808.283 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:31.520Z,1568991811.520 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:34.343Z,1568991814.343 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:37.583Z,1568991817.583 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:40.403Z,1568991820.403 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:42.815Z,1568991822.815 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:03:42.816Z,1568991822.816 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+0.0,1489.0,000 2019-09-20T15:03:43.231Z,1568991823.231 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:46.459Z,1568991826.459 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:49.283Z,1568991829.283 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:52.523Z,1568991832.523 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:55.363Z,1568991835.363 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:03:58.583Z,1568991838.583 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:01.410Z,1568991841.410 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:04.239Z,1568991844.239 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:07.471Z,1568991847.471 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:10.295Z,1568991850.295 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:13.527Z,1568991853.527 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:16.355Z,1568991856.355 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:19.587Z,1568991859.587 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:04:19.983Z,1568991859.983 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150336.00,A,3648.17713,N,12147.27499,W,0.505,39.17,200919,,,A*4B 2019-09-20T15:04:19.986Z,1568991859.986 [NAL9602](INFO): GPS fix at 20190920T150336: (36.802952, -121.787916) 2019-09-20T15:04:20.010Z,1568991860.010 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:04:20.010Z,1568991860.010 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:04:26.057Z,1568991866.057 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:04:26.057Z,1568991866.057 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+0.0,1489.WI,+00072,-0527,+0000,+00072,-00315,+00527,+00000,I 2019-09-20T15:04:29.779Z,1568991869.779 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190920T144658/Courier0007.lzma 2019-09-20T15:04:31.797Z,1568991871.797 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0007.lzma.bak 2019-09-20T15:04:31.797Z,1568991871.797 [DataOverHttps](INFO): SBD MOMSN=11790600 2019-09-20T15:04:52.305Z,1568991892.305 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:04:52.867Z,1568991892.867 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20190920T144658/Express0008.lzma 2019-09-20T15:04:54.873Z,1568991894.873 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0008.lzma.bak 2019-09-20T15:04:54.873Z,1568991894.873 [DataOverHttps](INFO): SBD MOMSN=11790603 2019-09-20T15:04:57.996Z,1568991897.996 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:04:57.996Z,1568991897.996 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:04:57.996Z,1568991897.996 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:05:37.254Z,1568991937.254 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+9999.99 2019-09-20T15:06:02.712Z,1568991962.712 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-09-20T15:06:45.939Z,1568992005.939 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:06:45.939Z,1568992005.939 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2019-09-20T15:07:03.711Z,1568992023.711 [DVL_micro](ERROR): Failed to parse: :WI,+00278,-00036,+00681,+00000,A 2019-09-20T15:08:11.602Z,1568992091.602 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:08:11.603Z,1568992091.603 [DVL_micro](ERROR): Failed to parse: :RD,+0011.08,+0011.04,+0010.92, 2019-09-20T15:09:58.722Z,1568992198.722 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:09:58.722Z,1568992198.722 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:09:58.722Z,1568992198.722 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:09:58.722Z,1568992198.722 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:09:59.105Z,1568992199.105 [Default:CheckIn:D] Stopped 2019-09-20T15:09:59.105Z,1568992199.105 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:09:59.508Z,1568992199.508 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.310142 min 2019-09-20T15:09:59.508Z,1568992199.508 [Default:CheckIn:E] Stopped 2019-09-20T15:09:59.508Z,1568992199.508 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:09:59.508Z,1568992199.508 [Default:CheckIn] Stopped 2019-09-20T15:09:59.508Z,1568992199.508 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:09:59.509Z,1568992199.509 [Default:CheckIn](INFO): Running loop #3 2019-09-20T15:09:59.509Z,1568992199.509 [Default:CheckIn] Running Loop=3 2019-09-20T15:09:59.509Z,1568992199.509 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:09:59.509Z,1568992199.509 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:10:01.107Z,1568992201.107 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:10:01.483Z,1568992201.483 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150918.00,A,3648.16799,N,12147.28172,W,0.447,285.92,200919,,,A*7E 2019-09-20T15:10:01.486Z,1568992201.486 [NAL9602](INFO): GPS fix at 20190920T150918: (36.802800, -121.788029) 2019-09-20T15:10:01.513Z,1568992201.513 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:10:01.513Z,1568992201.513 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:10:10.286Z,1568992210.286 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190920T144658/Courier0010.lzma 2019-09-20T15:10:12.293Z,1568992212.293 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0010.lzma.bak 2019-09-20T15:10:12.293Z,1568992212.293 [DataOverHttps](INFO): SBD MOMSN=11790607 2019-09-20T15:10:32.075Z,1568992232.075 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20190920T144658/Express0011.lzma 2019-09-20T15:10:34.081Z,1568992234.081 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0011.lzma.bak 2019-09-20T15:10:34.081Z,1568992234.081 [DataOverHttps](INFO): SBD MOMSN=11790610 2019-09-20T15:10:37.477Z,1568992237.477 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:10:37.478Z,1568992237.478 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:10:37.478Z,1568992237.478 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:10:41.886Z,1568992241.886 [NAL9602](INFO): SBD MO Status=2, MOMSN=1313, MT Status=2, MTMSN=0 2019-09-20T15:10:41.886Z,1568992241.886 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-20T15:10:46.743Z,1568992246.743 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:10:46.743Z,1568992246.743 [DVL_micro](ERROR): Failed to parse: :RD,+0000.314,+0000.35,+0002.68 2019-09-20T15:11:14.617Z,1568992274.617 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:11:14.617Z,1568992274.617 [DVL_micro](ERROR): Failed to parse: :RD,+0000.32,+00000.35,+0010.78 2019-09-20T15:11:40.096Z,1568992300.096 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:11:40.096Z,1568992300.096 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+1.0,1489.0,000 2019-09-20T15:12:04.334Z,1568992324.334 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:12:04.334Z,1568992324.334 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2019-09-20T15:14:23.699Z,1568992463.699 [DVL_micro](ERROR): Failed to parse: :WI,-00144,-00347,-00029,+00000,A 2019-09-20T15:14:57.256Z,1568992497.256 [DVL_micro](ERROR): Failed to parse: :WI,-00193,+00240,+00047,+00000,A 2019-09-20T15:15:03.310Z,1568992503.310 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-20T15:15:34.029Z,1568992534.029 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:15:38.112Z,1568992538.112 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:15:38.112Z,1568992538.112 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:15:38.112Z,1568992538.112 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:15:38.112Z,1568992538.112 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:15:38.508Z,1568992538.508 [Default:CheckIn:D] Stopped 2019-09-20T15:15:38.508Z,1568992538.508 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:15:38.989Z,1568992538.989 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.966846 min 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn:E] Stopped 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn] Stopped 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn](INFO): Running loop #4 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn] Running Loop=4 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:15:38.990Z,1568992538.990 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:15:40.503Z,1568992540.503 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:15:40.903Z,1568992540.903 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151458.00,A,3648.16762,N,12147.27914,W,0.156,285.92,200919,,,A*70 2019-09-20T15:15:40.905Z,1568992540.905 [NAL9602](INFO): GPS fix at 20190920T151458: (36.802794, -121.787986) 2019-09-20T15:15:40.934Z,1568992540.934 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:15:40.934Z,1568992540.934 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:15:47.373Z,1568992547.373 [DVL_micro](ERROR): Failed to parse: :RD,+00002.42,+00011.14 2019-09-20T15:15:49.611Z,1568992549.611 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190920T144658/Courier0013.lzma 2019-09-20T15:15:51.617Z,1568992551.617 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0013.lzma.bak 2019-09-20T15:15:51.617Z,1568992551.617 [DataOverHttps](INFO): SBD MOMSN=11790617 2019-09-20T15:16:10.887Z,1568992570.887 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20190920T144658/Express0014.lzma 2019-09-20T15:16:11.599Z,1568992571.599 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-09-20T15:16:11.675Z,1568992571.675 [NAL9602](FAULT): received: +CSQ:1 OK13, 2, 0, 0, 0 OK 2019-09-20T15:16:11.675Z,1568992571.675 [NAL9602] Data Fault, FailCount= 2 2019-09-20T15:16:11.675Z,1568992571.675 [NAL9602](ERROR): Data Fault 2019-09-20T15:16:11.743Z,1568992571.743 [CBIT](ERROR): Data Fault in component: NAL9602 2019-09-20T15:16:12.009Z,1568992572.009 [NAL9602](INFO): Powering down 2019-09-20T15:16:12.856Z,1568992572.856 [CBIT](INFO): Clearing failed state for component NAL9602 2019-09-20T15:16:12.856Z,1568992572.856 [NAL9602] No Fault, FailCount= 2 2019-09-20T15:16:12.893Z,1568992572.893 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0014.lzma.bak 2019-09-20T15:16:12.893Z,1568992572.893 [DataOverHttps](INFO): SBD MOMSN=11790620 2019-09-20T15:16:16.095Z,1568992576.095 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:16:16.095Z,1568992576.095 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:16:16.117Z,1568992576.117 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:16:16.875Z,1568992576.875 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:16:16.876Z,1568992576.876 [DVL_micro](ERROR): Failed to parse: :BI,+0011,-00019,+00000,A 2019-09-20T15:16:39.074Z,1568992599.074 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:16:39.074Z,1568992599.074 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.21489.0,000 2019-09-20T15:16:42.309Z,1568992602.309 [NAL9602](INFO): Powering up NAL9602 2019-09-20T15:16:53.217Z,1568992613.217 [NAL9602](INFO): NAL9602 initialized 2019-09-20T15:17:24.320Z,1568992644.320 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:17:32.813Z,1568992652.813 [DVL_micro](ERROR): Failed to parse: :BI,-00048,-00284,+00041,+00000,A0000000.00,+00000000.00,+00000000.00,0000.20,000.00 2019-09-20T15:18:26.546Z,1568992706.546 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,0000.20,000.00 2019-09-20T15:19:19.891Z,1568992759.891 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:19:19.891Z,1568992759.891 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,00.0,1489.WI,+00000,+00000,+00000,+00000,I 2019-09-20T15:19:46.132Z,1568992786.132 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:19:46.132Z,1568992786.132 [DVL_micro](ERROR): Failed to parse: :BI,-01432,+00074,+0000,A 2019-09-20T15:20:11.981Z,1568992811.981 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:20:11.981Z,1568992811.981 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+190,1489.0,000 2019-09-20T15:21:05.719Z,1568992865.719 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:21:05.719Z,1568992865.719 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.2,0000.0000 2019-09-20T15:21:16.671Z,1568992876.671 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:21:16.671Z,1568992876.671 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:21:16.671Z,1568992876.671 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:21:16.671Z,1568992876.671 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:21:17.064Z,1568992877.064 [Default:CheckIn:D] Stopped 2019-09-20T15:21:17.064Z,1568992877.064 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:21:17.476Z,1568992877.476 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.609452 min 2019-09-20T15:21:17.476Z,1568992877.476 [Default:CheckIn:E] Stopped 2019-09-20T15:21:17.476Z,1568992877.476 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:21:17.476Z,1568992877.476 [Default:CheckIn] Stopped 2019-09-20T15:21:17.476Z,1568992877.476 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:21:17.477Z,1568992877.477 [Default:CheckIn](INFO): Running loop #5 2019-09-20T15:21:17.477Z,1568992877.477 [Default:CheckIn] Running Loop=5 2019-09-20T15:21:17.477Z,1568992877.477 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:21:17.477Z,1568992877.477 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:21:19.066Z,1568992879.066 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:21:19.459Z,1568992879.459 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152035.00,A,3648.16842,N,12147.28291,W,0.311,353.89,200919,,,A*79 2019-09-20T15:21:19.461Z,1568992879.461 [NAL9602](INFO): GPS fix at 20190920T152035: (36.802807, -121.788049) 2019-09-20T15:21:19.524Z,1568992879.524 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:21:19.524Z,1568992879.524 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:21:21.065Z,1568992881.065 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-20T15:21:29.610Z,1568992889.610 [DVL_micro](ERROR): only read 2 of 4 data items 2019-09-20T15:21:29.610Z,1568992889.610 [DVL_micro](ERROR): Failed to parse: :RD,+00001.77,+00010.63 2019-09-20T15:21:32.535Z,1568992892.535 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190920T144658/Courier0016.lzma 2019-09-20T15:21:34.541Z,1568992894.541 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0016.lzma.bak 2019-09-20T15:21:34.541Z,1568992894.541 [DataOverHttps](INFO): SBD MOMSN=11790624 2019-09-20T15:21:51.805Z,1568992911.805 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:21:53.911Z,1568992913.911 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20190920T144658/Express0017.lzma 2019-09-20T15:21:55.917Z,1568992915.917 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0017.lzma.bak 2019-09-20T15:21:55.917Z,1568992915.917 [DataOverHttps](INFO): SBD MOMSN=11790628 2019-09-20T15:21:57.476Z,1568992917.476 [DVL_micro](ERROR): only read 1 of 4 data items 2019-09-20T15:21:57.476Z,1568992917.476 [DVL_micro](ERROR): Failed to parse: :RD,+0000..02,+0001.10,+0010.74 2019-09-20T15:21:59.151Z,1568992919.151 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:21:59.151Z,1568992919.151 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:21:59.151Z,1568992919.151 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:22:23.340Z,1568992943.340 [DVL_micro](ERROR): only read 0 of 4 data items 2019-09-20T15:22:23.340Z,1568992943.340 [DVL_micro](ERROR): Failed to parse: :RD,,+0000.490,+0010.62 2019-09-20T15:22:49.174Z,1568992969.174 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:22:49.175Z,1568992969.175 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+1.0,1489.0,000 2019-09-20T15:23:40.919Z,1568993020.919 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:23:40.919Z,1568993020.919 [DVL_micro](ERROR): Failed to parse: :TS,00000000000,+19.2,0000.0,1489.0,000 2019-09-20T15:24:08.405Z,1568993048.405 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2019-09-20T15:25:00.501Z,1568993100.501 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:25:00.501Z,1568993100.501 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.2,0000.0,148 2019-09-20T15:25:26.367Z,1568993126.367 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:25:26.367Z,1568993126.367 [DVL_micro](ERROR): Failed to parse: :RD,+0000.362,+0000.35,+0010.73 2019-09-20T15:26:59.739Z,1568993219.739 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:26:59.739Z,1568993219.739 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:26:59.739Z,1568993219.739 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:26:59.743Z,1568993219.743 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:27:00.139Z,1568993220.139 [Default:CheckIn:D] Stopped 2019-09-20T15:27:00.139Z,1568993220.139 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:27:00.524Z,1568993220.524 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.327368 min 2019-09-20T15:27:00.524Z,1568993220.524 [Default:CheckIn:E] Stopped 2019-09-20T15:27:00.524Z,1568993220.524 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:27:00.524Z,1568993220.524 [Default:CheckIn] Stopped 2019-09-20T15:27:00.524Z,1568993220.524 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:27:00.525Z,1568993220.525 [Default:CheckIn](INFO): Running loop #6 2019-09-20T15:27:00.525Z,1568993220.525 [Default:CheckIn] Running Loop=6 2019-09-20T15:27:00.525Z,1568993220.525 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:27:00.525Z,1568993220.525 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:27:02.127Z,1568993222.127 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:27:02.514Z,1568993222.514 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152619.00,A,3648.16300,N,12147.28413,W,0.311,353.89,200919,,,A*70 2019-09-20T15:27:02.517Z,1568993222.517 [NAL9602](INFO): GPS fix at 20190920T152619: (36.802717, -121.788069) 2019-09-20T15:27:02.597Z,1568993222.597 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:27:02.597Z,1568993222.597 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:27:09.786Z,1568993229.786 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:27:09.786Z,1568993229.786 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+0.0,1489.0,000 2019-09-20T15:27:11.543Z,1568993231.543 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190920T144658/Courier0019.lzma 2019-09-20T15:27:13.440Z,1568993233.440 [DVL_micro](ERROR): Failed to parse: 0.32,+0000.58,+0000.35,+0010.67 2019-09-20T15:27:13.549Z,1568993233.549 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0019.lzma.bak 2019-09-20T15:27:13.549Z,1568993233.549 [DataOverHttps](INFO): SBD MOMSN=11790639 2019-09-20T15:27:35.676Z,1568993255.676 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20190920T144658/Express0020.lzma 2019-09-20T15:27:37.681Z,1568993257.681 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0020.lzma.bak 2019-09-20T15:27:37.681Z,1568993257.681 [DataOverHttps](INFO): SBD MOMSN=11790642 2019-09-20T15:27:40.947Z,1568993260.947 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:27:40.947Z,1568993260.947 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:27:40.947Z,1568993260.947 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:28:57.264Z,1568993337.264 [DVL_micro](ERROR): only read 0 of 4 data items 2019-09-20T15:28:57.264Z,1568993337.264 [DVL_micro](ERROR): Failed to parse: :RD,,+0001.13,+0000.68,+0010.78 2019-09-20T15:30:18.498Z,1568993418.498 [DVL_micro](ERROR): Failed to parse: :.34,+0000.49,+0010.99,+0010.77 2019-09-20T15:30:44.348Z,1568993444.348 [DVL_micro](ERROR): Failed to parse: :SA,-00.59,-00.29,013.9 2019-09-20T15:31:22.307Z,1568993482.307 [NAL9602](INFO): SBD MO Status=2, MOMSN=1313, MT Status=2, MTMSN=0 2019-09-20T15:31:22.323Z,1568993482.323 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-20T15:31:38.059Z,1568993498.059 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:31:38.060Z,1568993498.060 [DVL_micro](ERROR): Failed to parse: :BI,+00000,+00000,+00000, 2019-09-20T15:31:59.478Z,1568993519.478 [NAL9602](INFO): SBD MO Status=2, MOMSN=1313, MT Status=2, MTMSN=0 2019-09-20T15:31:59.479Z,1568993519.479 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-20T15:32:02.296Z,1568993522.296 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,0000.20,000.00 2019-09-20T15:32:08.758Z,1568993528.758 [NAL9602](INFO): SBD MO Status=0, MOMSN=1313, MT Status=0, MTMSN=0 2019-09-20T15:32:08.758Z,1568993528.758 [NAL9602](INFO): No messages in MT queue 2019-09-20T15:32:39.488Z,1568993559.488 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:32:41.523Z,1568993561.523 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:32:41.523Z,1568993561.523 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:32:41.523Z,1568993561.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:32:41.527Z,1568993561.527 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:32:41.964Z,1568993561.964 [Default:CheckIn:D] Stopped 2019-09-20T15:32:41.964Z,1568993561.964 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:32:42.336Z,1568993562.336 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.024447 min 2019-09-20T15:32:42.336Z,1568993562.336 [Default:CheckIn:E] Stopped 2019-09-20T15:32:42.337Z,1568993562.337 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:32:42.337Z,1568993562.337 [Default:CheckIn] Stopped 2019-09-20T15:32:42.337Z,1568993562.337 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:32:42.337Z,1568993562.337 [Default:CheckIn](INFO): Running loop #7 2019-09-20T15:32:42.337Z,1568993562.337 [Default:CheckIn] Running Loop=7 2019-09-20T15:32:42.337Z,1568993562.337 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:32:42.337Z,1568993562.337 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:32:43.927Z,1568993563.927 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:32:44.315Z,1568993564.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153201.00,A,3648.16286,N,12147.28710,W,0.097,353.89,200919,,,A*7E 2019-09-20T15:32:44.317Z,1568993564.317 [NAL9602](INFO): GPS fix at 20190920T153201: (36.802714, -121.788118) 2019-09-20T15:32:44.342Z,1568993564.342 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:32:44.342Z,1568993564.342 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:32:53.927Z,1568993573.927 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190920T144658/Courier0022.lzma 2019-09-20T15:32:55.933Z,1568993575.933 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0022.lzma.bak 2019-09-20T15:32:55.933Z,1568993575.933 [DataOverHttps](INFO): SBD MOMSN=11790646 2019-09-20T15:33:15.559Z,1568993595.559 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20190920T144658/Express0023.lzma 2019-09-20T15:33:17.553Z,1568993597.553 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0023.lzma.bak 2019-09-20T15:33:17.553Z,1568993597.553 [DataOverHttps](INFO): SBD MOMSN=11790650 2019-09-20T15:33:21.115Z,1568993601.115 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:33:21.115Z,1568993601.115 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:33:21.115Z,1568993601.115 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:33:49.807Z,1568993629.807 [DVL_micro](ERROR): only read 0 of 4 data items 2019-09-20T15:33:49.807Z,1568993629.807 [DVL_micro](ERROR): Failed to parse: :RD,++0000.75,,+0011.19 2019-09-20T15:34:17.264Z,1568993657.264 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:34:17.264Z,1568993657.264 [DVL_micro](ERROR): Failed to parse: :BI,+00101,-00059,-0000,A 2019-09-20T15:34:43.130Z,1568993683.130 [DVL_micro](ERROR): Failed to parse: :WI,+0000,+00000,+000I,-00380,+00007,-00137,+00000,A 2019-09-20T15:35:09.375Z,1568993709.375 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:35:09.375Z,1568993709.375 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,.1,0000.0,1489.0,000 2019-09-20T15:35:10.852Z,1568993710.852 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 500.000000 cubic_centimeter 2019-09-20T15:35:10.853Z,1568993710.853 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2019-09-20T15:35:11.085Z,1568993711.085 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-09-20T15:35:23.321Z,1568993723.321 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position 2019-09-20T15:35:23.593Z,1568993723.593 [Reporter](INFO): platform_buoyancy_position 858.552734 cc 2019-09-20T15:35:23.977Z,1568993723.977 [Reporter](INFO): platform_buoyancy_position 852.912109 cc 2019-09-20T15:35:24.445Z,1568993724.445 [Reporter](INFO): platform_buoyancy_position 846.465698 cc 2019-09-20T15:35:24.857Z,1568993724.857 [Reporter](INFO): platform_buoyancy_position 842.033813 cc 2019-09-20T15:35:25.147Z,1568993725.147 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:35:25.147Z,1568993725.147 [DVL_micro](ERROR): Failed to parse: :RD,+0000.68,+0001.14,+00011.29 2019-09-20T15:35:25.354Z,1568993725.354 [Reporter](INFO): platform_buoyancy_position 835.587402 cc 2019-09-20T15:35:25.661Z,1568993725.661 [Reporter](INFO): platform_buoyancy_position 831.289795 cc 2019-09-20T15:35:26.113Z,1568993726.113 [Reporter](INFO): platform_buoyancy_position 824.977661 cc 2019-09-20T15:35:26.498Z,1568993726.498 [Reporter](INFO): platform_buoyancy_position 820.545776 cc 2019-09-20T15:35:26.919Z,1568993726.919 [Reporter](INFO): platform_buoyancy_position 814.099365 cc 2019-09-20T15:35:27.341Z,1568993727.341 [Reporter](INFO): platform_buoyancy_position 808.861694 cc 2019-09-20T15:35:27.744Z,1568993727.744 [Reporter](INFO): platform_buoyancy_position 803.489685 cc 2019-09-20T15:35:28.221Z,1568993728.221 [Reporter](INFO): platform_buoyancy_position 797.043274 cc 2019-09-20T15:35:28.553Z,1568993728.553 [Reporter](INFO): platform_buoyancy_position 792.879944 cc 2019-09-20T15:35:28.921Z,1568993728.921 [Reporter](INFO): platform_buoyancy_position 788.313782 cc 2019-09-20T15:35:29.380Z,1568993729.380 [Reporter](INFO): platform_buoyancy_position 782.001648 cc 2019-09-20T15:35:29.752Z,1568993729.752 [Reporter](INFO): platform_buoyancy_position 777.569763 cc 2019-09-20T15:35:30.172Z,1568993730.172 [Reporter](INFO): platform_buoyancy_position 771.257690 cc 2019-09-20T15:35:30.557Z,1568993730.557 [Reporter](INFO): platform_buoyancy_position 767.094360 cc 2019-09-20T15:35:30.965Z,1568993730.965 [Reporter](INFO): platform_buoyancy_position 762.662476 cc 2019-09-20T15:35:31.333Z,1568993731.333 [Reporter](INFO): platform_buoyancy_position 756.216064 cc 2019-09-20T15:35:31.788Z,1568993731.788 [Reporter](INFO): platform_buoyancy_position 750.978394 cc 2019-09-20T15:35:32.173Z,1568993732.173 [Reporter](INFO): platform_buoyancy_position 745.472046 cc 2019-09-20T15:35:32.541Z,1568993732.541 [Reporter](INFO): platform_buoyancy_position 741.174500 cc 2019-09-20T15:35:32.993Z,1568993732.993 [Reporter](INFO): platform_buoyancy_position 734.728088 cc 2019-09-20T15:35:33.343Z,1568993733.343 [Reporter](INFO): platform_buoyancy_position 730.296143 cc 2019-09-20T15:35:33.747Z,1568993733.747 [Reporter](INFO): platform_buoyancy_position 724.118347 cc 2019-09-20T15:35:34.133Z,1568993734.133 [Reporter](INFO): platform_buoyancy_position 719.552185 cc 2019-09-20T15:35:34.537Z,1568993734.537 [Reporter](INFO): platform_buoyancy_position 715.254578 cc 2019-09-20T15:35:34.874Z,1568993734.874 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2019-09-20T15:35:35.009Z,1568993735.009 [Reporter](INFO): platform_buoyancy_position 708.808167 cc 2019-09-20T15:35:35.329Z,1568993735.329 [Reporter](INFO): platform_buoyancy_position 704.376282 cc 2019-09-20T15:35:35.744Z,1568993735.744 [Reporter](INFO): platform_buoyancy_position 698.064148 cc 2019-09-20T15:35:36.160Z,1568993736.160 [Reporter](INFO): platform_buoyancy_position 693.766541 cc 2019-09-20T15:35:36.577Z,1568993736.577 [Reporter](INFO): platform_buoyancy_position 687.320190 cc 2019-09-20T15:35:36.989Z,1568993736.989 [Reporter](INFO): platform_buoyancy_position 682.619690 cc 2019-09-20T15:35:37.357Z,1568993737.357 [Reporter](INFO): platform_buoyancy_position 676.576172 cc 2019-09-20T15:35:37.758Z,1568993737.758 [Reporter](INFO): platform_buoyancy_position 672.412842 cc 2019-09-20T15:35:38.142Z,1568993738.142 [Reporter](INFO): platform_buoyancy_position 667.846680 cc 2019-09-20T15:35:38.553Z,1568993738.553 [Reporter](INFO): platform_buoyancy_position 661.534546 cc 2019-09-20T15:35:38.977Z,1568993738.977 [Reporter](INFO): platform_buoyancy_position 655.222473 cc 2019-09-20T15:35:39.381Z,1568993739.381 [Reporter](INFO): platform_buoyancy_position 650.790588 cc 2019-09-20T15:35:39.794Z,1568993739.794 [Reporter](INFO): platform_buoyancy_position 645.955750 cc 2019-09-20T15:35:40.177Z,1568993740.177 [Reporter](INFO): platform_buoyancy_position 640.180847 cc 2019-09-20T15:35:40.597Z,1568993740.597 [Reporter](INFO): platform_buoyancy_position 635.614685 cc 2019-09-20T15:35:41.009Z,1568993741.009 [Reporter](INFO): platform_buoyancy_position 629.436890 cc 2019-09-20T15:35:41.385Z,1568993741.385 [Reporter](INFO): platform_buoyancy_position 625.139282 cc 2019-09-20T15:35:41.794Z,1568993741.794 [Reporter](INFO): platform_buoyancy_position 620.170166 cc 2019-09-20T15:35:42.205Z,1568993742.205 [Reporter](INFO): platform_buoyancy_position 614.260986 cc 2019-09-20T15:35:42.621Z,1568993742.621 [Reporter](INFO): platform_buoyancy_position 608.620361 cc 2019-09-20T15:35:43.044Z,1568993743.044 [Reporter](INFO): platform_buoyancy_position 603.516968 cc 2019-09-20T15:35:43.397Z,1568993743.397 [Reporter](INFO): platform_buoyancy_position 599.085083 cc 2019-09-20T15:35:43.829Z,1568993743.829 [Reporter](INFO): platform_buoyancy_position 592.772949 cc 2019-09-20T15:35:44.218Z,1568993744.218 [Reporter](INFO): platform_buoyancy_position 588.206787 cc 2019-09-20T15:35:44.633Z,1568993744.633 [Reporter](INFO): platform_buoyancy_position 582.028931 cc 2019-09-20T15:35:45.033Z,1568993745.033 [Reporter](INFO): platform_buoyancy_position 577.597046 cc 2019-09-20T15:35:45.436Z,1568993745.436 [Reporter](INFO): platform_buoyancy_position 571.419250 cc 2019-09-20T15:35:45.852Z,1568993745.852 [Reporter](INFO): platform_buoyancy_position 566.584473 cc 2019-09-20T15:35:46.265Z,1568993746.265 [Reporter](INFO): platform_buoyancy_position 560.675232 cc 2019-09-20T15:35:46.681Z,1568993746.681 [Reporter](INFO): platform_buoyancy_position 554.228882 cc 2019-09-20T15:35:47.098Z,1568993747.098 [Reporter](INFO): platform_buoyancy_position 549.796936 cc 2019-09-20T15:35:47.473Z,1568993747.473 [Reporter](INFO): platform_buoyancy_position 545.499329 cc 2019-09-20T15:35:47.845Z,1568993747.845 [Reporter](INFO): platform_buoyancy_position 539.187256 cc 2019-09-20T15:35:48.249Z,1568993748.249 [Reporter](INFO): platform_buoyancy_position 534.889648 cc 2019-09-20T15:35:48.676Z,1568993748.676 [Reporter](INFO): platform_buoyancy_position 528.308960 cc 2019-09-20T15:35:49.096Z,1568993749.096 [Reporter](INFO): platform_buoyancy_position 524.011353 cc 2019-09-20T15:35:49.501Z,1568993749.501 [Reporter](INFO): platform_buoyancy_position 517.699280 cc 2019-09-20T15:35:49.877Z,1568993749.877 [Reporter](INFO): platform_buoyancy_position 513.267334 cc 2019-09-20T15:35:50.309Z,1568993750.309 [Reporter](INFO): platform_buoyancy_position 508.969696 cc 2019-09-20T15:35:52.765Z,1568993752.765 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200.000000 cubic_centimeter 2019-09-20T15:35:53.974Z,1568993753.974 [Reporter](INFO): platform_buoyancy_position 504.672180 cc 2019-09-20T15:35:54.720Z,1568993754.720 [Reporter](INFO): platform_buoyancy_position 502.657684 cc 2019-09-20T15:35:55.137Z,1568993755.137 [Reporter](INFO): platform_buoyancy_position 496.076935 cc 2019-09-20T15:35:55.525Z,1568993755.525 [Reporter](INFO): platform_buoyancy_position 491.913635 cc 2019-09-20T15:35:55.917Z,1568993755.917 [Reporter](INFO): platform_buoyancy_position 489.764862 cc 2019-09-20T15:35:56.325Z,1568993756.325 [Reporter](INFO): platform_buoyancy_position 485.332947 cc 2019-09-20T15:35:56.741Z,1568993756.741 [Reporter](INFO): platform_buoyancy_position 479.020874 cc 2019-09-20T15:35:57.164Z,1568993757.164 [Reporter](INFO): platform_buoyancy_position 474.588928 cc 2019-09-20T15:35:57.565Z,1568993757.565 [Reporter](INFO): platform_buoyancy_position 468.276855 cc 2019-09-20T15:35:57.953Z,1568993757.953 [Reporter](INFO): platform_buoyancy_position 463.979248 cc 2019-09-20T15:35:58.369Z,1568993758.369 [Reporter](INFO): platform_buoyancy_position 459.547363 cc 2019-09-20T15:35:58.793Z,1568993758.793 [Reporter](INFO): platform_buoyancy_position 453.235229 cc 2019-09-20T15:35:59.296Z,1568993759.296 [Reporter](INFO): platform_buoyancy_position 446.654541 cc 2019-09-20T15:35:59.577Z,1568993759.577 [Reporter](INFO): platform_buoyancy_position 442.356934 cc 2019-09-20T15:36:00.018Z,1568993760.018 [Reporter](INFO): platform_buoyancy_position 436.044861 cc 2019-09-20T15:36:00.393Z,1568993760.393 [Reporter](INFO): platform_buoyancy_position 431.747253 cc 2019-09-20T15:36:00.861Z,1568993760.861 [Reporter](INFO): platform_buoyancy_position 425.300842 cc 2019-09-20T15:36:01.243Z,1568993761.243 [Reporter](INFO): platform_buoyancy_position 421.003235 cc 2019-09-20T15:36:01.601Z,1568993761.601 [Reporter](INFO): platform_buoyancy_position 416.571350 cc 2019-09-20T15:36:02.021Z,1568993762.021 [Reporter](INFO): platform_buoyancy_position 410.124939 cc 2019-09-20T15:36:02.436Z,1568993762.436 [Reporter](INFO): platform_buoyancy_position 405.693054 cc 2019-09-20T15:36:02.845Z,1568993762.845 [Reporter](INFO): platform_buoyancy_position 399.515259 cc 2019-09-20T15:36:03.229Z,1568993763.229 [Reporter](INFO): platform_buoyancy_position 395.217651 cc 2019-09-20T15:36:03.636Z,1568993763.636 [Reporter](INFO): platform_buoyancy_position 388.636963 cc 2019-09-20T15:36:04.004Z,1568993764.004 [Reporter](INFO): platform_buoyancy_position 384.339355 cc 2019-09-20T15:36:04.409Z,1568993764.409 [Reporter](INFO): platform_buoyancy_position 380.041748 cc 2019-09-20T15:36:04.825Z,1568993764.825 [Reporter](INFO): platform_buoyancy_position 373.729614 cc 2019-09-20T15:36:05.225Z,1568993765.225 [Reporter](INFO): platform_buoyancy_position 368.894836 cc 2019-09-20T15:36:05.617Z,1568993765.617 [Reporter](INFO): platform_buoyancy_position 362.985657 cc 2019-09-20T15:36:06.033Z,1568993766.033 [Reporter](INFO): platform_buoyancy_position 358.419434 cc 2019-09-20T15:36:06.445Z,1568993766.445 [Reporter](INFO): platform_buoyancy_position 352.107361 cc 2019-09-20T15:36:06.861Z,1568993766.861 [Reporter](INFO): platform_buoyancy_position 347.944031 cc 2019-09-20T15:36:07.269Z,1568993767.269 [Reporter](INFO): platform_buoyancy_position 341.497620 cc 2019-09-20T15:36:07.649Z,1568993767.649 [Reporter](INFO): platform_buoyancy_position 337.065735 cc 2019-09-20T15:36:08.068Z,1568993768.068 [Reporter](INFO): platform_buoyancy_position 330.619324 cc 2019-09-20T15:36:08.481Z,1568993768.481 [Reporter](INFO): platform_buoyancy_position 326.321716 cc 2019-09-20T15:36:08.853Z,1568993768.853 [Reporter](INFO): platform_buoyancy_position 321.889832 cc 2019-09-20T15:36:09.261Z,1568993769.261 [Reporter](INFO): platform_buoyancy_position 315.712036 cc 2019-09-20T15:36:09.653Z,1568993769.653 [Reporter](INFO): platform_buoyancy_position 311.280151 cc 2019-09-20T15:36:10.062Z,1568993770.062 [Reporter](INFO): platform_buoyancy_position 304.968048 cc 2019-09-20T15:36:10.473Z,1568993770.473 [Reporter](INFO): platform_buoyancy_position 300.670441 cc 2019-09-20T15:36:10.893Z,1568993770.893 [Reporter](INFO): platform_buoyancy_position 294.089722 cc 2019-09-20T15:36:11.290Z,1568993771.290 [Reporter](INFO): platform_buoyancy_position 289.926422 cc 2019-09-20T15:36:11.673Z,1568993771.673 [Reporter](INFO): platform_buoyancy_position 283.345734 cc 2019-09-20T15:36:12.117Z,1568993772.117 [Reporter](INFO): platform_buoyancy_position 278.108032 cc 2019-09-20T15:36:12.505Z,1568993772.505 [Reporter](INFO): platform_buoyancy_position 272.736023 cc 2019-09-20T15:36:12.925Z,1568993772.925 [Reporter](INFO): platform_buoyancy_position 268.169830 cc 2019-09-20T15:36:13.301Z,1568993773.301 [Reporter](INFO): platform_buoyancy_position 261.992035 cc 2019-09-20T15:36:13.705Z,1568993773.705 [Reporter](INFO): platform_buoyancy_position 257.560120 cc 2019-09-20T15:36:14.117Z,1568993774.117 [Reporter](INFO): platform_buoyancy_position 251.516647 cc 2019-09-20T15:36:14.529Z,1568993774.529 [Reporter](INFO): platform_buoyancy_position 246.681824 cc 2019-09-20T15:36:14.945Z,1568993774.945 [Reporter](INFO): platform_buoyancy_position 240.504028 cc 2019-09-20T15:36:15.333Z,1568993775.333 [Reporter](INFO): platform_buoyancy_position 236.072144 cc 2019-09-20T15:36:15.749Z,1568993775.749 [Reporter](INFO): platform_buoyancy_position 230.028625 cc 2019-09-20T15:36:16.129Z,1568993776.129 [Reporter](INFO): platform_buoyancy_position 225.462433 cc 2019-09-20T15:36:16.537Z,1568993776.537 [Reporter](INFO): platform_buoyancy_position 221.030518 cc 2019-09-20T15:36:17.009Z,1568993777.009 [Reporter](INFO): platform_buoyancy_position 214.584137 cc 2019-09-20T15:36:17.401Z,1568993777.401 [Reporter](INFO): platform_buoyancy_position 208.137726 cc 2019-09-20T15:36:20.280Z,1568993780.280 [CommandLine](IMPORTANT): got command report mod Onboard.Humidity 2019-09-20T15:36:20.542Z,1568993780.542 [Reporter](INFO): Onboard.Humidity 8.826761 % 2019-09-20T15:36:21.780Z,1568993781.780 [Reporter](INFO): Onboard.Humidity 8.838969 % 2019-09-20T15:36:22.603Z,1568993782.603 [Reporter](INFO): Onboard.Humidity 8.826761 % 2019-09-20T15:36:24.179Z,1568993784.179 [Reporter](INFO): Onboard.Humidity 8.838969 % 2019-09-20T15:36:25.010Z,1568993785.010 [Reporter](INFO): Onboard.Humidity 8.826761 % 2019-09-20T15:36:26.977Z,1568993786.977 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:36:26.977Z,1568993786.977 [DVL_micro](ERROR): Failed to parse: :RD,+0000.32,+0001.02,+00011.22 2019-09-20T15:36:27.430Z,1568993787.430 [Reporter](INFO): Onboard.Humidity 8.838969 % 2019-09-20T15:36:28.211Z,1568993788.211 [Reporter](INFO): Onboard.Humidity 8.826761 % 2019-09-20T15:36:29.028Z,1568993789.028 [Reporter](INFO): Onboard.Humidity 8.838969 % 2019-09-20T15:36:30.662Z,1568993790.662 [Reporter](INFO): Onboard.Humidity 8.826761 % 2019-09-20T15:36:32.276Z,1568993792.276 [Reporter](INFO): Onboard.Humidity 8.838969 % 2019-09-20T15:36:33.108Z,1568993793.108 [Reporter](INFO): Onboard.Humidity 8.826761 % 2019-09-20T15:36:34.040Z,1568993794.040 [CommandLine](IMPORTANT): got command report clear 2019-09-20T15:36:42.640Z,1568993802.640 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position 2019-09-20T15:36:42.795Z,1568993802.795 [Reporter](INFO): platform_buoyancy_position 208.137726 cc 2019-09-20T15:36:56.466Z,1568993816.466 [DVL_micro](ERROR): Failed to parse: :.82,+0000.98,+0001.82,+0011.23 2019-09-20T15:37:46.169Z,1568993866.169 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-20T15:38:16.065Z,1568993896.065 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:38:16.065Z,1568993896.065 [DVL_micro](ERROR): Failed to parse: :BI,+00508,+00038,-00005A 2019-09-20T15:38:16.871Z,1568993896.871 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:38:21.751Z,1568993901.751 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:38:21.751Z,1568993901.751 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:38:21.751Z,1568993901.751 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:38:21.751Z,1568993901.751 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:38:22.192Z,1568993902.192 [Default:CheckIn:D] Stopped 2019-09-20T15:38:22.192Z,1568993902.192 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:38:22.581Z,1568993902.581 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.694918 min 2019-09-20T15:38:22.581Z,1568993902.581 [Default:CheckIn:E] Stopped 2019-09-20T15:38:22.582Z,1568993902.582 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:38:22.582Z,1568993902.582 [Default:CheckIn] Stopped 2019-09-20T15:38:22.582Z,1568993902.582 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:38:22.582Z,1568993902.582 [Default:CheckIn](INFO): Running loop #8 2019-09-20T15:38:22.582Z,1568993902.582 [Default:CheckIn] Running Loop=8 2019-09-20T15:38:22.582Z,1568993902.582 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:38:22.582Z,1568993902.582 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:38:24.171Z,1568993904.171 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:38:24.534Z,1568993904.534 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153741.00,A,3648.16026,N,12147.28754,W,0.894,224.34,200919,,,A*7B 2019-09-20T15:38:24.537Z,1568993904.537 [NAL9602](INFO): GPS fix at 20190920T153741: (36.802671, -121.788126) 2019-09-20T15:38:24.595Z,1568993904.595 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:38:24.595Z,1568993904.595 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:38:27.173Z,1568993907.173 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190920T144658/Courier0025.lzma 2019-09-20T15:38:29.181Z,1568993909.181 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0025.lzma.bak 2019-09-20T15:38:29.181Z,1568993909.181 [DataOverHttps](INFO): SBD MOMSN=11790657 2019-09-20T15:38:35.946Z,1568993915.946 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2019-09-20T15:38:48.568Z,1568993928.568 [DataOverHttps](INFO): Sending 347 bytes from file Logs/20190920T144658/Express0026.lzma 2019-09-20T15:38:50.573Z,1568993930.573 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0026.lzma.bak 2019-09-20T15:38:50.573Z,1568993930.573 [DataOverHttps](INFO): SBD MOMSN=11790660 2019-09-20T15:38:53.727Z,1568993933.727 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:38:53.751Z,1568993933.751 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:38:53.751Z,1568993933.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:39:02.185Z,1568993942.185 [DVL_micro](ERROR): Failed to parse: 00000.00,+00000000.00,+00000000.00,0000.50,000.00 2019-09-20T15:39:05.841Z,1568993945.841 [DVL_micro](ERROR): Failed to parse: 0.59,+00010.89,+0010.99 2019-09-20T15:39:33.720Z,1568993973.720 [DVL_micro](ERROR): Failed to parse: :SA,+02.60,+05.11,024.3 2019-09-20T15:39:43.823Z,1568993983.823 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:39:43.823Z,1568993983.823 [DVL_micro](ERROR): Failed to parse: :BI,-00005,-00172,-00012A 2019-09-20T15:39:52.290Z,1568993992.290 [NAL9602](INFO): SBD MO Status=2, MOMSN=1314, MT Status=2, MTMSN=0 2019-09-20T15:39:52.290Z,1568993992.290 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-20T15:40:01.588Z,1568994001.588 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:40:01.588Z,1568994001.588 [DVL_micro](ERROR): Failed to parse: :BI,+00368,-0038,+00000,A 2019-09-20T15:40:27.846Z,1568994027.846 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:40:27.847Z,1568994027.847 [DVL_micro](ERROR): Failed to parse: :BI,+00003,-00021,-00007,+00000+00000000.00,+00000000.00,+00000000.00,0009.40,000.00 2019-09-20T15:40:41.592Z,1568994041.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=1314, MT Status=0, MTMSN=0 2019-09-20T15:40:41.592Z,1568994041.592 [NAL9602](INFO): No messages in MT queue 2019-09-20T15:41:12.274Z,1568994072.274 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:41:59.547Z,1568994119.547 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:41:59.547Z,1568994119.547 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+0.0,1489.0I,+00000,+0000,+000I,-00155,-00965,-00246,+00000,A 2019-09-20T15:42:51.262Z,1568994171.262 [DVL_micro](ERROR): Failed to parse: :W,+00000,+00000,+00000,I 2019-09-20T15:43:43.035Z,1568994223.035 [DVL_micro](ERROR): DVL uart error: serial timeout 2019-09-20T15:43:43.035Z,1568994223.035 [DVL_micro] Communications Fault, FailCount= 1 2019-09-20T15:43:43.035Z,1568994223.035 [DVL_micro](ERROR): Communications Fault 2019-09-20T15:43:43.036Z,1568994223.036 [DVL_micro](ERROR): Failed to parse: 2019-09-20T15:43:43.125Z,1568994223.125 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-20T15:43:43.447Z,1568994223.447 [DVL_micro](INFO): Powering down 2019-09-20T15:43:44.225Z,1568994224.225 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-20T15:43:44.225Z,1568994224.225 [DVL_micro] No Fault, FailCount= 1 2019-09-20T15:43:54.335Z,1568994234.335 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:43:54.335Z,1568994234.335 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:43:54.335Z,1568994234.335 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:43:54.339Z,1568994234.339 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:43:54.758Z,1568994234.758 [Default:CheckIn:D] Stopped 2019-09-20T15:43:54.758Z,1568994234.758 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:43:55.136Z,1568994235.136 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.237691 min 2019-09-20T15:43:55.136Z,1568994235.136 [Default:CheckIn:E] Stopped 2019-09-20T15:43:55.136Z,1568994235.136 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:43:55.136Z,1568994235.136 [Default:CheckIn] Stopped 2019-09-20T15:43:55.136Z,1568994235.136 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:43:55.137Z,1568994235.137 [Default:CheckIn](INFO): Running loop #9 2019-09-20T15:43:55.137Z,1568994235.137 [Default:CheckIn] Running Loop=9 2019-09-20T15:43:55.137Z,1568994235.137 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:43:55.137Z,1568994235.137 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:43:56.719Z,1568994236.719 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:43:57.115Z,1568994237.115 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154314.00,A,3648.16562,N,12147.28301,W,0.233,224.34,200919,,,A*7E 2019-09-20T15:43:57.117Z,1568994237.117 [NAL9602](INFO): GPS fix at 20190920T154314: (36.802760, -121.788050) 2019-09-20T15:43:57.173Z,1568994237.173 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:43:57.173Z,1568994237.173 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:44:06.962Z,1568994246.962 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190920T144658/Courier0028.lzma 2019-09-20T15:44:08.969Z,1568994248.969 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0028.lzma.bak 2019-09-20T15:44:08.969Z,1568994248.969 [DataOverHttps](INFO): SBD MOMSN=11790675 2019-09-20T15:44:28.255Z,1568994268.255 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190920T144658/Express0029.lzma 2019-09-20T15:44:30.261Z,1568994270.261 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0029.lzma.bak 2019-09-20T15:44:30.261Z,1568994270.261 [DataOverHttps](INFO): SBD MOMSN=11790678 2019-09-20T15:44:33.188Z,1568994273.188 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:44:33.188Z,1568994273.188 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:44:33.188Z,1568994273.188 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:44:49.271Z,1568994289.271 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:44:49.271Z,1568994289.271 [DVL_micro](ERROR): Failed to parse: :TS,00000000000,+19.1,0000.0,1489.0,000 2019-09-20T15:45:13.106Z,1568994313.106 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:45:13.106Z,1568994313.106 [DVL_micro](ERROR): Failed to parse: :BI,-00729,-00597,-0000,A 2019-09-20T15:45:38.977Z,1568994338.977 [DVL_micro](ERROR): only read 2 of 4 data items 2019-09-20T15:45:38.977Z,1568994338.977 [DVL_micro](ERROR): Failed to parse: :RD,+0000.32,+0000..35,+0010.77 2019-09-20T15:46:06.469Z,1568994366.469 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.20,000.00 2019-09-20T15:46:30.691Z,1568994390.691 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:46:30.692Z,1568994390.692 [DVL_micro](ERROR): Failed to parse::TS,00000000000000,35.0,+19.1,0000.0,1489:WI,+00000,+00000,+00000,+00000,I 2019-09-20T15:46:56.566Z,1568994416.566 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:46:56.566Z,1568994416.566 [DVL_micro](ERROR): Failed to parse: :BI,+01531,+00270,-00309, 2019-09-20T15:47:22.397Z,1568994442.397 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:47:22.397Z,1568994442.397 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.1,489.0,000 2019-09-20T15:47:44.239Z,1568994464.239 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:47:44.240Z,1568994464.240 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2019-09-20T15:47:48.258Z,1568994468.258 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:47:48.259Z,1568994468.259 [DVL_micro](ERROR): Failed to parse: :TS,000000005.0,+19.1,0000.0,1489.0,000 2019-09-20T15:48:53.307Z,1568994533.307 [NAL9602](INFO): SBD MO Status=0, MOMSN=1315, MT Status=0, MTMSN=0 2019-09-20T15:48:53.307Z,1568994533.307 [NAL9602](INFO): No messages in MT queue 2019-09-20T15:49:24.008Z,1568994564.008 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:49:33.749Z,1568994573.749 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:49:33.749Z,1568994573.749 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:49:33.749Z,1568994573.749 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:49:33.749Z,1568994573.749 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:49:34.170Z,1568994574.170 [Default:CheckIn:D] Stopped 2019-09-20T15:49:34.170Z,1568994574.170 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:49:34.557Z,1568994574.557 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.894556 min 2019-09-20T15:49:34.557Z,1568994574.557 [Default:CheckIn:E] Stopped 2019-09-20T15:49:34.558Z,1568994574.558 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:49:34.558Z,1568994574.558 [Default:CheckIn] Stopped 2019-09-20T15:49:34.558Z,1568994574.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:49:34.558Z,1568994574.558 [Default:CheckIn](INFO): Running loop #10 2019-09-20T15:49:34.558Z,1568994574.558 [Default:CheckIn] Running Loop=10 2019-09-20T15:49:34.558Z,1568994574.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:49:34.558Z,1568994574.558 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:49:36.139Z,1568994576.139 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:49:36.532Z,1568994576.532 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154853.00,A,3648.16629,N,12147.28494,W,0.156,224.34,200919,,,A*71 2019-09-20T15:49:36.534Z,1568994576.534 [NAL9602](INFO): GPS fix at 20190920T154853: (36.802771, -121.788082) 2019-09-20T15:49:36.559Z,1568994576.559 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:49:36.559Z,1568994576.559 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:49:46.351Z,1568994586.351 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190920T144658/Courier0031.lzma 2019-09-20T15:49:48.357Z,1568994588.357 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0031.lzma.bak 2019-09-20T15:49:48.357Z,1568994588.357 [DataOverHttps](INFO): SBD MOMSN=11790681 2019-09-20T15:50:02.794Z,1568994602.794 [NAL9602](INFO): SBD MO Status=0, MOMSN=1316, MT Status=0, MTMSN=0 2019-09-20T15:50:02.794Z,1568994602.794 [NAL9602](INFO): No messages in MT queue 2019-09-20T15:50:07.591Z,1568994607.591 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20190920T144658/Express0032.lzma 2019-09-20T15:50:09.597Z,1568994609.597 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0032.lzma.bak 2019-09-20T15:50:09.597Z,1568994609.597 [DataOverHttps](INFO): SBD MOMSN=11790684 2019-09-20T15:50:12.535Z,1568994612.535 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:50:12.535Z,1568994612.535 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:50:12.539Z,1568994612.539 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:50:33.493Z,1568994633.493 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:52:08.844Z,1568994728.844 [DVL_micro](ERROR): Failed to parse: :BI,+00071,-0002,+00000,A 2019-09-20T15:52:50.497Z,1568994770.497 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:52:50.497Z,1568994770.497 [DVL_micro](ERROR): Failed to parse: :BI,-00755,-0054,+00000,A 2019-09-20T15:53:00.240Z,1568994780.240 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:53:00.240Z,1568994780.240 [DVL_micro](ERROR): Failed to parse: :BI,-0199,+00168,+00000,A 2019-09-20T15:53:10.312Z,1568994790.312 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2019-09-20T15:53:20.386Z,1568994800.386 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:53:20.387Z,1568994800.387 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35,0000.0,1489.0,000 2019-09-20T15:53:24.165Z,1568994804.165 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:53:24.165Z,1568994804.165 [DVL_micro](ERROR): Failed to parse: :BI,-00135,-00688,-00132,+00000+00000000.00,+00000000.00,+00000000.00,0000.20,000.00 2019-09-20T15:53:36.245Z,1568994816.245 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2019-09-20T15:53:56.054Z,1568994836.054 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-20T15:53:56.054Z,1568994836.054 [DVL_micro](ERROR): Failed to parse: :BI,-00875,-0019,+00000,A 2019-09-20T15:54:34.017Z,1568994874.017 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+0.0,1489.WI,+0000,+00000,+00000,I 2019-09-20T15:54:47.759Z,1568994887.759 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:54:47.759Z,1568994887.759 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+1.0,1489.0,000 2019-09-20T15:55:01.898Z,1568994901.898 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:55:01.899Z,1568994901.899 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+19.1,0000.0,1489.0,000 2019-09-20T15:55:13.270Z,1568994913.270 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-20T15:55:13.270Z,1568994913.270 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:55:13.270Z,1568994913.270 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:55:13.270Z,1568994913.270 [Default:CheckIn:D] Running Loop=1 2019-09-20T15:55:13.683Z,1568994913.683 [Default:CheckIn:D] Stopped 2019-09-20T15:55:13.683Z,1568994913.683 [Default:CheckIn:E] Running Loop=1 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.553101 min 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn:E] Stopped 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn] Stopped 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn](INFO): Running loop #11 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn] Running Loop=11 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-20T15:55:14.050Z,1568994914.050 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-20T15:55:15.667Z,1568994915.667 [NAL9602](DEBUG): Fix Requested 2019-09-20T15:55:16.039Z,1568994916.039 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155433.00,A,3648.16120,N,12147.28559,W,0.097,0.00,200919,,,A*7B 2019-09-20T15:55:16.057Z,1568994916.057 [NAL9602](INFO): GPS fix at 20190920T155433: (36.802687, -121.788093) 2019-09-20T15:55:16.081Z,1568994916.081 [Default:CheckIn:Read_GPS] Stopped 2019-09-20T15:55:16.081Z,1568994916.081 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-20T15:55:25.311Z,1568994925.311 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190920T144658/Courier0034.lzma 2019-09-20T15:55:25.735Z,1568994925.735 [DVL_micro](ERROR): Failed to parse: :WI,-01187,+00000,+00000,+00000,I 2019-09-20T15:55:27.317Z,1568994927.317 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Courier0034.lzma.bak 2019-09-20T15:55:27.317Z,1568994927.317 [DataOverHttps](INFO): SBD MOMSN=11790697 2019-09-20T15:55:49.219Z,1568994949.219 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190920T144658/Express0035.lzma 2019-09-20T15:55:51.229Z,1568994951.229 [DataOverHttps](INFO): Moved sent file to Logs/20190920T144658/Express0035.lzma.bak 2019-09-20T15:55:51.230Z,1568994951.230 [DataOverHttps](INFO): SBD MOMSN=11790700 2019-09-20T15:55:54.461Z,1568994954.461 [Default:CheckIn:Read_Iridium] Stopped 2019-09-20T15:55:54.461Z,1568994954.461 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-20T15:55:54.461Z,1568994954.461 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-20T15:56:17.454Z,1568994977.454 [DVL_micro](ERROR): only read 0 of 4 data items 2019-09-20T15:56:17.454Z,1568994977.454 [DVL_micro](ERROR): Failed to parse: :RD,++0001.295,+0010.88 2019-09-20T15:57:05.925Z,1568995025.925 [NAL9602](INFO): SBD MO Status=2, MOMSN=1317, MT Status=2, MTMSN=0 2019-09-20T15:57:05.926Z,1568995025.926 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-20T15:58:00.410Z,1568995080.410 [CommandLine](INFO): End of History 2019-09-20T15:58:00.422Z,1568995080.422 [CommandLine](INFO): End of History 2019-09-20T15:58:00.463Z,1568995080.463 [CommandLine](INFO): End of History 2019-09-20T15:58:00.466Z,1568995080.466 [CommandLine](INFO): End of History 2019-09-20T15:58:00.476Z,1568995080.476 [CommandLine](INFO): End of History 2019-09-20T15:58:00.478Z,1568995080.478 [CommandLine](INFO): End of History 2019-09-20T15:58:02.891Z,1568995082.891 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-20T15:58:02.891Z,1568995082.891 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.1,000.0,000 2019-09-20T15:58:03.294Z,1568995083.294 [NAL9602](INFO): SBD MO Status=0, MOMSN=1317, MT Status=0, MTMSN=0 2019-09-20T15:58:03.294Z,1568995083.294 [NAL9602](INFO): No messages in MT queue 2019-09-20T15:58:30.381Z,1568995110.381 [DVL_micro](ERROR): only read 2 of 4 data items 2019-09-20T15:58:30.382Z,1568995110.382 [DVL_micro](ERROR): Failed to parse: :BI,+0106,-0000,A 2019-09-20T15:58:33.814Z,1568995113.814 [CommandLine](IMPORTANT): got command restart application 2019-09-20T15:58:33.996Z,1568995113.996 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-20T15:58:34.823Z,1568995114.823 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:34.824Z,1568995114.824 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:34.967Z,1568995114.967 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-09-20T15:58:34.967Z,1568995114.967 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:34.968Z,1568995114.968 [CommandLine](INFO): Join timeout helper Thread ID is 9207 2019-09-20T15:58:34.969Z,1568995114.969 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-09-20T15:58:34.969Z,1568995114.969 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:34.970Z,1568995114.970 [NavChartDb](INFO): Join timeout helper Thread ID is 9208 2019-09-20T15:58:35.143Z,1568995115.143 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:35.143Z,1568995115.143 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:35.150Z,1568995115.150 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-09-20T15:58:35.150Z,1568995115.150 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:35.151Z,1568995115.151 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9209 2019-09-20T15:58:35.376Z,1568995115.376 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:35.376Z,1568995115.376 [WetLabsBB2FL](INFO): Powering down 2019-09-20T15:58:35.377Z,1568995115.377 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:35.395Z,1568995115.395 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-09-20T15:58:35.395Z,1568995115.395 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:35.396Z,1568995115.396 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9210 2019-09-20T15:58:35.840Z,1568995115.840 [CTD_Seabird](INFO): Powering down 2019-09-20T15:58:35.855Z,1568995115.855 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:35.855Z,1568995115.855 [CTD_Seabird](INFO): Powering down 2019-09-20T15:58:35.867Z,1568995115.867 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:35.875Z,1568995115.875 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-09-20T15:58:35.875Z,1568995115.875 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:35.876Z,1568995115.876 [Radio_Surface](INFO): Join timeout helper Thread ID is 9211 2019-09-20T15:58:36.179Z,1568995116.179 [Radio_Surface](INFO): Powering down 2019-09-20T15:58:36.180Z,1568995116.180 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:36.180Z,1568995116.180 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:36.188Z,1568995116.188 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-09-20T15:58:36.188Z,1568995116.188 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:36.189Z,1568995116.189 [DataOverHttps](INFO): Join timeout helper Thread ID is 9212 2019-09-20T15:58:37.187Z,1568995117.187 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:37.191Z,1568995117.191 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.204Z,1568995117.204 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-09-20T15:58:37.204Z,1568995117.204 [logger ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.204Z,1568995117.204 [logger](INFO): Join timeout helper Thread ID is 9213 2019-09-20T15:58:37.236Z,1568995117.236 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:37.236Z,1568995117.236 [logger ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.248Z,1568995117.248 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-09-20T15:58:37.248Z,1568995117.248 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.248Z,1568995117.248 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-09-20T15:58:37.248Z,1568995117.248 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.249Z,1568995117.249 [controlThread](INFO): Join timeout helper Thread ID is 9214 2019-09-20T15:58:37.269Z,1568995117.269 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-20T15:58:37.269Z,1568995117.269 [controlThread](DEBUG): Uninitializing ControlThread 2019-09-20T15:58:37.270Z,1568995117.270 [AHRS_M2](INFO): Powering down 2019-09-20T15:58:37.411Z,1568995117.411 [DVL_micro](INFO): Powering down 2019-09-20T15:58:37.412Z,1568995117.412 [NAL9602](INFO): Powering down 2019-09-20T15:58:37.413Z,1568995117.413 [DAT](INFO): Powering down 2019-09-20T15:58:37.532Z,1568995117.532 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-09-20T15:58:37.533Z,1568995117.533 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-09-20T15:58:37.534Z,1568995117.534 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-09-20T15:58:37.534Z,1568995117.534 [MissionManager](INFO): Uninitializing Mission Default 2019-09-20T15:58:37.534Z,1568995117.534 [Default] Stopped 2019-09-20T15:58:37.534Z,1568995117.534 [Default](DEBUG): Aggregate::uninitialize Default 2019-09-20T15:58:37.535Z,1568995117.535 [Default:B.GoToSurface] Stopped 2019-09-20T15:58:37.535Z,1568995117.535 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-09-20T15:58:37.535Z,1568995117.535 [Default:CheckIn] Stopped 2019-09-20T15:58:37.535Z,1568995117.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-20T15:58:37.535Z,1568995117.535 [Default:CheckIn:C.Wait] Stopped 2019-09-20T15:58:37.535Z,1568995117.535 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-20T15:58:37.537Z,1568995117.537 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-09-20T15:58:37.538Z,1568995117.538 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-09-20T15:58:37.538Z,1568995117.538 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-09-20T15:58:37.538Z,1568995117.538 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-09-20T15:58:37.538Z,1568995117.538 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-09-20T15:58:37.539Z,1568995117.539 [BuoyancyServo](INFO): Powering down 2019-09-20T15:58:37.551Z,1568995117.551 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-09-20T15:58:37.551Z,1568995117.551 [ElevatorServo](INFO): Powering down 2019-09-20T15:58:37.552Z,1568995117.552 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-09-20T15:58:37.552Z,1568995117.552 [MassServo](INFO): Powering down 2019-09-20T15:58:37.553Z,1568995117.553 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-09-20T15:58:37.553Z,1568995117.553 [RudderServo](INFO): Powering down 2019-09-20T15:58:37.554Z,1568995117.554 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-09-20T15:58:37.554Z,1568995117.554 [ThrusterServo](INFO): Powering down 2019-09-20T15:58:37.555Z,1568995117.555 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-09-20T15:58:37.555Z,1568995117.555 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-09-20T15:58:37.555Z,1568995117.555 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-09-20T15:58:37.555Z,1568995117.555 [CBIT](DEBUG): Powering off loads. 2019-09-20T15:58:37.567Z,1568995117.567 [CBIT](DEBUG): Disabling WDT. 2019-09-20T15:58:37.579Z,1568995117.579 [CBIT](DEBUG): Opening all GF detection circuits. 2019-09-20T15:58:37.580Z,1568995117.580 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.676Z,1568995117.676 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.684Z,1568995117.684 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.731Z,1568995117.731 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.734Z,1568995117.734 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.779Z,1568995117.779 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-20T15:58:37.849Z,1568995117.849 [logger ThreadHandler](INFO): Thread cancelled.