2019-10-01T13:52:33.779Z,1569937953.779 [Supervisor](DEBUG): Initializing supervisor. 2019-10-01T13:52:33.782Z,1569937953.782 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-10-01T13:52:33.783Z,1569937953.783 [SyncHandler](INFO): Protected caller Thread ID is 5885 2019-10-01T13:52:33.783Z,1569937953.783 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-10-01T13:52:33.784Z,1569937953.784 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-10-01T13:52:33.784Z,1569937953.784 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5886 2019-10-01T13:52:33.787Z,1569937953.787 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-10-01T13:52:33.798Z,1569937953.798 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-10-01T13:52:33.799Z,1569937953.799 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-10-01T13:52:33.799Z,1569937953.799 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5887 2019-10-01T13:52:33.800Z,1569937953.800 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-10-01T13:52:33.801Z,1569937953.801 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-10-01T13:52:33.801Z,1569937953.801 [logger ThreadHandler](INFO): Protected caller Thread ID is 5888 2019-10-01T13:52:33.803Z,1569937953.803 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-10-01T13:52:33.803Z,1569937953.803 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-10-01T13:52:33.805Z,1569937953.805 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-10-01T13:52:33.962Z,1569937953.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-10-01T13:52:33.963Z,1569937953.963 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-10-01T13:52:34.160Z,1569937954.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-10-01T13:52:34.161Z,1569937954.161 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-10-01T13:52:34.294Z,1569937954.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-10-01T13:52:34.295Z,1569937954.295 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-10-01T13:52:34.848Z,1569937954.848 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-10-01T13:52:34.848Z,1569937954.848 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-10-01T13:52:35.276Z,1569937955.276 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-10-01T13:52:35.277Z,1569937955.277 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-10-01T13:52:35.731Z,1569937955.731 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-10-01T13:52:35.732Z,1569937955.732 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-10-01T13:52:36.028Z,1569937956.028 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-10-01T13:52:36.029Z,1569937956.029 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-10-01T13:52:36.419Z,1569937956.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-10-01T13:52:36.420Z,1569937956.420 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-10-01T13:52:36.804Z,1569937956.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-10-01T13:52:36.805Z,1569937956.805 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-10-01T13:52:36.949Z,1569937956.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-10-01T13:52:36.950Z,1569937956.950 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-10-01T13:52:37.052Z,1569937957.052 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-10-01T13:52:37.053Z,1569937957.053 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-10-01T13:52:37.134Z,1569937957.134 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-10-01T13:52:37.234Z,1569937957.234 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-10-01T13:52:37.235Z,1569937957.235 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-10-01T13:52:37.422Z,1569937957.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-10-01T13:52:37.423Z,1569937957.423 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-10-01T13:52:37.624Z,1569937957.624 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-10-01T13:52:37.626Z,1569937957.626 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2019-10-01T13:52:37.627Z,1569937957.627 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2019-10-01T13:52:37.710Z,1569937957.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2019-10-01T13:52:37.932Z,1569937957.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-10-01T13:52:37.933Z,1569937957.933 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2019-10-01T13:52:38.026Z,1569937958.026 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2019-10-01T13:52:38.186Z,1569937958.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2019-10-01T13:52:38.382Z,1569937958.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2019-10-01T13:52:38.466Z,1569937958.466 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2019-10-01T13:52:38.565Z,1569937958.565 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2019-10-01T13:52:38.656Z,1569937958.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2019-10-01T13:52:38.980Z,1569937958.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2019-10-01T13:52:39.445Z,1569937959.445 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2019-10-01T13:52:40.065Z,1569937960.065 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2019-10-01T13:52:40.065Z,1569937960.065 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-10-01T13:52:40.067Z,1569937960.067 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-10-01T13:52:40.167Z,1569937960.167 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-10-01T13:52:40.168Z,1569937960.168 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-10-01T13:52:40.274Z,1569937960.274 [BuoyancyServo] Loaded 2019-10-01T13:52:40.274Z,1569937960.274 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-10-01T13:52:40.289Z,1569937960.289 [ElevatorServo] Loaded 2019-10-01T13:52:40.290Z,1569937960.290 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-10-01T13:52:40.304Z,1569937960.304 [MassServo] Loaded 2019-10-01T13:52:40.304Z,1569937960.304 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-10-01T13:52:40.319Z,1569937960.319 [RudderServo] Loaded 2019-10-01T13:52:40.319Z,1569937960.319 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-10-01T13:52:40.333Z,1569937960.333 [ThrusterServo] Loaded 2019-10-01T13:52:40.333Z,1569937960.333 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-10-01T13:52:40.334Z,1569937960.334 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-10-01T13:52:40.334Z,1569937960.334 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-10-01T13:52:40.468Z,1569937960.468 [SBIT](DEBUG): Construct Startup Built In Test. 2019-10-01T13:52:40.496Z,1569937960.496 [SBIT] Loaded 2019-10-01T13:52:40.497Z,1569937960.497 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-10-01T13:52:40.497Z,1569937960.497 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-10-01T13:52:40.524Z,1569937960.524 [IBIT] Loaded 2019-10-01T13:52:40.524Z,1569937960.524 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-10-01T13:52:40.527Z,1569937960.527 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-10-01T13:52:40.912Z,1569937960.912 [CBIT] Loaded 2019-10-01T13:52:40.912Z,1569937960.912 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-10-01T13:52:40.913Z,1569937960.913 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-10-01T13:52:40.913Z,1569937960.913 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-10-01T13:52:41.095Z,1569937961.095 [Aanderaa_O2] Loaded 2019-10-01T13:52:41.095Z,1569937961.095 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2019-10-01T13:52:41.104Z,1569937961.104 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-10-01T13:52:41.109Z,1569937961.109 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-10-01T13:52:41.111Z,1569937961.111 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-10-01T13:52:41.116Z,1569937961.116 [CTD_Seabird](INFO): created writer for : depth 2019-10-01T13:52:41.116Z,1569937961.116 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-10-01T13:52:41.121Z,1569937961.121 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-10-01T13:52:41.122Z,1569937961.122 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-10-01T13:52:41.127Z,1569937961.127 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-10-01T13:52:41.127Z,1569937961.127 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-10-01T13:52:41.133Z,1569937961.133 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-10-01T13:52:41.134Z,1569937961.134 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-10-01T13:52:41.139Z,1569937961.139 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-10-01T13:52:41.139Z,1569937961.139 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-10-01T13:52:41.144Z,1569937961.144 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-10-01T13:52:41.170Z,1569937961.170 [CTD_Seabird] Loaded 2019-10-01T13:52:41.170Z,1569937961.170 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-10-01T13:52:41.172Z,1569937961.172 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4066B4E0 2019-10-01T13:52:41.172Z,1569937961.172 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5968 2019-10-01T13:52:41.202Z,1569937961.202 [ESPComponent] Loaded 2019-10-01T13:52:41.202Z,1569937961.202 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-10-01T13:52:41.216Z,1569937961.216 [PAR_Licor] Loaded 2019-10-01T13:52:41.216Z,1569937961.216 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-10-01T13:52:41.222Z,1569937961.222 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2019-10-01T13:52:41.223Z,1569937961.223 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2019-10-01T13:52:41.227Z,1569937961.227 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2019-10-01T13:52:41.227Z,1569937961.227 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2019-10-01T13:52:41.231Z,1569937961.231 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2019-10-01T13:52:41.231Z,1569937961.231 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2019-10-01T13:52:41.235Z,1569937961.236 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2019-10-01T13:52:41.236Z,1569937961.236 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2019-10-01T13:52:41.240Z,1569937961.240 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2019-10-01T13:52:41.240Z,1569937961.240 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2019-10-01T13:52:41.244Z,1569937961.244 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2019-10-01T13:52:41.245Z,1569937961.245 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2019-10-01T13:52:41.249Z,1569937961.249 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2019-10-01T13:52:41.249Z,1569937961.249 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2019-10-01T13:52:41.253Z,1569937961.253 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.258Z,1569937961.258 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.258Z,1569937961.258 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.259Z,1569937961.259 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.263Z,1569937961.263 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.263Z,1569937961.263 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.267Z,1569937961.267 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.268Z,1569937961.268 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-10-01T13:52:41.272Z,1569937961.272 [WetLabsBB2FL] Loaded 2019-10-01T13:52:41.272Z,1569937961.272 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-10-01T13:52:41.273Z,1569937961.273 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4069B4E0 2019-10-01T13:52:41.274Z,1569937961.274 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5969 2019-10-01T13:52:41.274Z,1569937961.274 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-10-01T13:52:41.275Z,1569937961.275 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-10-01T13:52:41.315Z,1569937961.315 [DepthRateCalculator] Loaded 2019-10-01T13:52:41.316Z,1569937961.316 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-10-01T13:52:41.321Z,1569937961.321 [PitchRateCalculator] Loaded 2019-10-01T13:52:41.322Z,1569937961.322 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-10-01T13:52:41.337Z,1569937961.337 [SpeedCalculator] Loaded 2019-10-01T13:52:41.337Z,1569937961.337 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-10-01T13:52:41.358Z,1569937961.358 [TempGradientCalculator] Loaded 2019-10-01T13:52:41.358Z,1569937961.358 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-10-01T13:52:41.364Z,1569937961.364 [YawRateCalculator] Loaded 2019-10-01T13:52:41.364Z,1569937961.364 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-10-01T13:52:41.396Z,1569937961.396 [ElevatorOffsetCalculator] Loaded 2019-10-01T13:52:41.397Z,1569937961.397 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-10-01T13:52:41.397Z,1569937961.397 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-10-01T13:52:41.398Z,1569937961.398 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-10-01T13:52:41.430Z,1569937961.430 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-10-01T13:52:41.430Z,1569937961.430 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-10-01T13:52:41.532Z,1569937961.532 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-10-01T13:52:41.532Z,1569937961.532 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-10-01T13:52:41.552Z,1569937961.552 [NavChart] Loaded 2019-10-01T13:52:41.553Z,1569937961.553 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-10-01T13:52:41.557Z,1569937961.557 [UniversalFixResidualReporter] Loaded 2019-10-01T13:52:41.557Z,1569937961.557 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-10-01T13:52:41.557Z,1569937961.557 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-10-01T13:52:41.558Z,1569937961.558 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-10-01T13:52:41.794Z,1569937961.794 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-10-01T13:52:41.798Z,1569937961.798 [AHRS_M2](INFO): created writer for : platform_orientation 2019-10-01T13:52:41.799Z,1569937961.799 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-10-01T13:52:41.804Z,1569937961.804 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-10-01T13:52:41.805Z,1569937961.805 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-10-01T13:52:41.810Z,1569937961.810 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-10-01T13:52:41.810Z,1569937961.810 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-10-01T13:52:41.815Z,1569937961.815 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-10-01T13:52:41.888Z,1569937961.888 [AHRS_M2] Loaded 2019-10-01T13:52:41.888Z,1569937961.888 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-10-01T13:52:41.963Z,1569937961.963 [DataOverHttps] Loaded 2019-10-01T13:52:41.964Z,1569937961.964 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-10-01T13:52:41.965Z,1569937961.965 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409634E0 2019-10-01T13:52:41.965Z,1569937961.965 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5970 2019-10-01T13:52:41.978Z,1569937961.978 [Depth_Keller] Loaded 2019-10-01T13:52:41.979Z,1569937961.979 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-10-01T13:52:41.983Z,1569937961.983 [DropWeight] Loaded 2019-10-01T13:52:41.984Z,1569937961.984 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-10-01T13:52:42.029Z,1569937962.029 [DVL_micro] Loaded 2019-10-01T13:52:42.029Z,1569937962.029 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-10-01T13:52:42.119Z,1569937962.119 [NAL9602] Loaded 2019-10-01T13:52:42.119Z,1569937962.119 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-10-01T13:52:42.124Z,1569937962.124 [Onboard] Loaded 2019-10-01T13:52:42.125Z,1569937962.125 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-10-01T13:52:42.128Z,1569937962.128 [Radio_Surface] Loaded 2019-10-01T13:52:42.128Z,1569937962.128 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-10-01T13:52:42.129Z,1569937962.129 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409934E0 2019-10-01T13:52:42.130Z,1569937962.130 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5971 2019-10-01T13:52:42.251Z,1569937962.251 [DAT] Loaded 2019-10-01T13:52:42.251Z,1569937962.251 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-10-01T13:52:43.521Z,1569937963.521 [BPC1] Loaded 2019-10-01T13:52:43.521Z,1569937963.521 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-10-01T13:52:43.522Z,1569937963.522 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-10-01T13:52:43.522Z,1569937963.522 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-10-01T13:52:43.592Z,1569937963.592 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-10-01T13:52:43.593Z,1569937963.593 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-10-01T13:52:43.659Z,1569937963.659 [VerticalControl](DEBUG): Construct VerticalControl. 2019-10-01T13:52:43.742Z,1569937963.742 [VerticalControl] Loaded 2019-10-01T13:52:43.743Z,1569937963.743 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-10-01T13:52:43.743Z,1569937963.743 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-10-01T13:52:43.801Z,1569937963.801 [HorizontalControl] Loaded 2019-10-01T13:52:43.801Z,1569937963.801 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-10-01T13:52:43.802Z,1569937963.802 [SpeedControl](DEBUG): Construct SpeedControl. 2019-10-01T13:52:43.803Z,1569937963.803 [SpeedControl] Loaded 2019-10-01T13:52:43.804Z,1569937963.804 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-10-01T13:52:43.804Z,1569937963.804 [LoopControl](DEBUG): Construct LoopControl. 2019-10-01T13:52:43.805Z,1569937963.805 [LoopControl] Loaded 2019-10-01T13:52:43.805Z,1569937963.805 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-10-01T13:52:43.806Z,1569937963.806 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-10-01T13:52:43.806Z,1569937963.806 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-10-01T13:52:43.819Z,1569937963.819 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-10-01T13:52:43.820Z,1569937963.820 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-10-01T13:52:44.109Z,1569937964.109 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-10-01T13:52:44.124Z,1569937964.124 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-10-01T13:52:44.124Z,1569937964.124 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-10-01T13:52:44.143Z,1569937964.143 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-10-01T13:52:44.144Z,1569937964.144 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0 2019-10-01T13:52:44.144Z,1569937964.144 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5972 2019-10-01T13:52:44.157Z,1569937964.157 [Supervisor](INFO): Main Thread ID is 5884 2019-10-01T13:52:44.157Z,1569937964.157 [Supervisor](DEBUG): Running supervisor. 2019-10-01T13:52:44.194Z,1569937964.194 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5973 2019-10-01T13:52:44.196Z,1569937964.196 [controlThread ThreadHandler](INFO): Handler Thread ID is 5974 2019-10-01T13:52:44.197Z,1569937964.197 [logger ThreadHandler](INFO): Handler Thread ID is 5975 2019-10-01T13:52:44.200Z,1569937964.200 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5976 2019-10-01T13:52:44.200Z,1569937964.200 [controlThread](DEBUG): Initializing ControlThread 2019-10-01T13:52:44.202Z,1569937964.202 [SBIT](INFO): Initialize SBIT Component. 2019-10-01T13:52:44.203Z,1569937964.203 [SBIT](IMPORTANT): git: 2019-10-01_A 2019-10-01T13:52:44.203Z,1569937964.203 [SBIT](INFO): git hash: 45f1fece079aa3565d4a3aba33a016ea6943a305 2019-10-01T13:52:44.203Z,1569937964.203 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-10-01T13:52:44.204Z,1569937964.204 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-10-01T13:52:44.206Z,1569937964.206 [SBIT](INFO): Beginning SBIT in 52.000000 seconds. 2019-10-01T13:52:44.206Z,1569937964.206 [IBIT](INFO): Initialize IBIT Component. 2019-10-01T13:52:44.207Z,1569937964.207 [CBIT](DEBUG): Initialize CBIT Component. 2019-10-01T13:52:44.208Z,1569937964.208 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-10-01T13:52:44.211Z,1569937964.211 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-10-01T13:52:44.212Z,1569937964.212 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5978 2019-10-01T13:52:44.213Z,1569937964.213 [WetLabsBB2FL](INFO): Powering down 2019-10-01T13:52:44.221Z,1569937964.221 [CBIT](DEBUG): Initialized mux pins. 2019-10-01T13:52:44.222Z,1569937964.222 [CBIT](DEBUG): Initializing the watchdog timer. 2019-10-01T13:52:44.245Z,1569937964.245 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-10-01T13:52:44.245Z,1569937964.245 [CBIT](DEBUG): Initializing heartbeat. 2019-10-01T13:52:44.262Z,1569937964.262 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5979 2019-10-01T13:52:44.263Z,1569937964.263 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-10-01T13:52:44.277Z,1569937964.277 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5980 2019-10-01T13:52:44.294Z,1569937964.294 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5981 2019-10-01T13:52:44.299Z,1569937964.299 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-10-01T13:52:44.300Z,1569937964.300 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-10-01T13:52:44.300Z,1569937964.300 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-10-01T13:52:44.300Z,1569937964.300 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-10-01T13:52:44.300Z,1569937964.300 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-10-01T13:52:44.300Z,1569937964.300 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-10-01T13:52:44.300Z,1569937964.300 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-10-01T13:52:44.301Z,1569937964.301 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-10-01T13:52:44.301Z,1569937964.301 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-10-01T13:52:44.301Z,1569937964.301 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-10-01T13:52:44.301Z,1569937964.301 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-10-01T13:52:44.301Z,1569937964.301 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-10-01T13:52:44.302Z,1569937964.302 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-10-01T13:52:44.302Z,1569937964.302 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-10-01T13:52:44.302Z,1569937964.302 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-10-01T13:52:44.302Z,1569937964.302 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-10-01T13:52:44.317Z,1569937964.317 [CBIT](DEBUG): Deactivating GF circuits. 2019-10-01T13:52:44.318Z,1569937964.318 [CBIT](DEBUG): Deactivating emergency mode. 2019-10-01T13:52:44.353Z,1569937964.353 [CBIT](DEBUG): Backplane powered. 2019-10-01T13:52:44.358Z,1569937964.358 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-10-01T13:52:44.358Z,1569937964.358 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-10-01T13:52:44.358Z,1569937964.358 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-10-01T13:52:44.359Z,1569937964.359 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-10-01T13:52:44.359Z,1569937964.359 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-10-01T13:52:44.360Z,1569937964.360 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-10-01T13:52:44.361Z,1569937964.361 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-10-01T13:52:44.361Z,1569937964.361 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-10-01T13:52:44.372Z,1569937964.372 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-10-01T13:52:44.382Z,1569937964.382 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-10-01T13:52:44.383Z,1569937964.383 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-10-01T13:52:44.383Z,1569937964.383 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-10-01T13:52:44.384Z,1569937964.384 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-10-01T13:52:44.419Z,1569937964.419 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-01T13:52:44.459Z,1569937964.459 [MissionManager](DEBUG): 2019-10-01T13:52:44.459Z,1569937964.459 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-10-01T13:52:44.525Z,1569937964.525 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-10-01T13:52:44.550Z,1569937964.550 [Default:A.Wait](DEBUG): Construct Wait. 2019-10-01T13:52:44.552Z,1569937964.552 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-01T13:52:44.571Z,1569937964.571 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-10-01T13:52:44.606Z,1569937964.606 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-10-01T13:52:44.611Z,1569937964.611 [Default:E.Execute](DEBUG): Construct Execute. 2019-10-01T13:52:44.624Z,1569937964.624 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-10-01T13:52:44.639Z,1569937964.639 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-10-01T13:52:44.678Z,1569937964.678 [Radio_Surface](INFO): Powering up 2019-10-01T13:52:44.695Z,1569937964.695 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-10-01T13:52:44.857Z,1569937964.857 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-10-01T13:52:44.857Z,1569937964.857 [DAT](INFO): Powering up 2019-10-01T13:52:44.858Z,1569937964.858 [DAT](DEBUG): Initializing DAT. 2019-10-01T13:52:44.900Z,1569937964.900 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-10-01T13:52:44.969Z,1569937964.969 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-10-01T13:52:44.994Z,1569937964.994 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-10-01T13:52:44.995Z,1569937964.995 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-10-01T13:52:45.006Z,1569937965.006 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-10-01T13:52:45.007Z,1569937965.007 [MassServo](DEBUG): Initializing EZServoServo. 2019-10-01T13:52:45.018Z,1569937965.018 [MassServo](DEBUG): Initializing MassServo. 2019-10-01T13:52:45.019Z,1569937965.019 [RudderServo](DEBUG): Initializing EZServoServo. 2019-10-01T13:52:45.030Z,1569937965.030 [RudderServo](DEBUG): Initializing RudderServo. 2019-10-01T13:52:45.031Z,1569937965.031 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-10-01T13:52:45.042Z,1569937965.042 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-10-01T13:52:48.002Z,1569937968.002 [Aanderaa_O2](INFO): Powering down 2019-10-01T13:52:51.238Z,1569937971.238 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2019-10-01T13:53:00.242Z,1569937980.242 [DAT](INFO): setting local address to 3 2019-10-01T13:53:00.647Z,1569937980.647 [DAT](INFO): set local address to 3 2019-10-01T13:53:01.775Z,1569937981.775 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004587 2019-10-01T13:53:12.348Z,1569937992.348 [NAL9602](INFO): Powering up NAL9602 2019-10-01T13:53:23.256Z,1569938003.256 [NAL9602](INFO): NAL9602 initialized 2019-10-01T13:53:24.078Z,1569938004.078 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:53:24.566Z,1569938004.566 [DVL_micro](ERROR): DVL uart error: serial timeout 2019-10-01T13:53:24.566Z,1569938004.566 [DVL_micro] Communications Fault, FailCount= 1 2019-10-01T13:53:24.566Z,1569938004.566 [DVL_micro](ERROR): Communications Fault 2019-10-01T13:53:24.566Z,1569938004.566 [DVL_micro](ERROR): Failed to parse: 2019-10-01T13:53:24.690Z,1569938004.690 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-01T13:53:24.942Z,1569938004.942 [DVL_micro](INFO): Powering down 2019-10-01T13:53:25.759Z,1569938005.759 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-01T13:53:25.759Z,1569938005.759 [DVL_micro] No Fault, FailCount= 1 2019-10-01T13:53:36.696Z,1569938016.696 [SBIT](IMPORTANT): Beginning Startup BIT 2019-10-01T13:53:36.704Z,1569938016.704 [CBIT](IMPORTANT): Beginning ground fault scan 2019-10-01T13:53:46.812Z,1569938026.812 [DVL_micro](ERROR): Failed to parse: :4,+00132,-00258,+00000,I 2019-10-01T13:53:47.697Z,1569938027.697 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.011237 CHAN A1 (24V): -0.013920 CHAN A2 (12V): -0.001691 CHAN A3 (5V): -0.001689 CHAN B0 (3.3V): -0.001095 CHAN B1 (3.15aV): -0.001505 CHAN B2 (3.15bV): -0.001458 CHAN B3 (GND): -0.002163 OPEN: 0.007337 Full Scale Calc: 4.765 mA, -1.589 mA 2019-10-01T13:54:06.820Z,1569938046.820 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+9999.99 2019-10-01T13:54:30.005Z,1569938070.005 [SBIT](IMPORTANT): SBIT PASSED 2019-10-01T13:54:30.070Z,1569938070.070 [CommandLine](IMPORTANT): got command configSet list 2019-10-01T13:54:30.070Z,1569938070.070 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-10-01T13:54:30.071Z,1569938070.071 [CommandLine](IMPORTANT): No configSet variables persisted 2019-10-01T13:54:30.383Z,1569938070.383 [MissionManager](IMPORTANT): Started mission Startup 2019-10-01T13:54:30.383Z,1569938070.383 [Startup] Running Loop=1 2019-10-01T13:54:30.383Z,1569938070.383 [Startup](DEBUG): Aggregate::initialize Startup 2019-10-01T13:54:30.383Z,1569938070.383 [Startup:A.GoToSurface] Running Loop=1 2019-10-01T13:54:30.383Z,1569938070.383 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-01T13:54:30.384Z,1569938070.384 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-01T13:54:30.385Z,1569938070.385 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-01T13:54:30.385Z,1569938070.385 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-01T13:54:30.385Z,1569938070.385 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-01T13:54:30.386Z,1569938070.386 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-01T13:54:30.387Z,1569938070.387 [Startup:StartupSatComms] Running Loop=1 2019-10-01T13:54:30.387Z,1569938070.387 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-10-01T13:54:30.387Z,1569938070.387 [Startup:StartupSatComms:A] Running Loop=1 2019-10-01T13:54:30.780Z,1569938070.780 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-10-01T13:54:54.204Z,1569938094.204 [BPC1](ERROR): BPC1A failed to parse battery stick message. 2019-10-01T13:55:21.048Z,1569938121.048 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T13:55:30.572Z,1569938130.572 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-01T13:54:30.4Z 2019-10-01T13:55:30.572Z,1569938130.572 [Startup:StartupSatComms:A] Stopped 2019-10-01T13:55:30.572Z,1569938130.572 [Startup:StartupSatComms:B] Running Loop=1 2019-10-01T13:55:30.983Z,1569938130.983 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-01T13:55:37.749Z,1569938137.749 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191001T004619/Courier0223.lzma 2019-10-01T13:55:39.756Z,1569938139.756 [DataOverHttps](INFO): Moved sent file to Logs/20191001T004619/Courier0223.lzma.bak 2019-10-01T13:55:39.756Z,1569938139.756 [DataOverHttps](INFO): SBD MOMSN=11835626 2019-10-01T13:55:44.696Z,1569938144.696 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-10-01T13:55:44.696Z,1569938144.696 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T13:55:44.725Z,1569938144.725 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T13:55:45.149Z,1569938145.149 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T13:55:45.149Z,1569938145.149 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-10-01T13:56:02.134Z,1569938162.134 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T13:56:06.572Z,1569938166.572 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20191001T004619/Express0224.lzma 2019-10-01T13:56:08.555Z,1569938168.555 [DataOverHttps](INFO): Moved sent file to Logs/20191001T004619/Express0224.lzma.bak 2019-10-01T13:56:08.556Z,1569938168.556 [DataOverHttps](INFO): SBD MOMSN=11835628 2019-10-01T13:56:27.583Z,1569938187.583 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-10-01T13:56:30.762Z,1569938190.762 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-01T13:55:30.6Z 2019-10-01T13:56:30.762Z,1569938190.762 [Startup:StartupSatComms:B] Stopped 2019-10-01T13:56:30.762Z,1569938190.762 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-10-01T13:56:30.763Z,1569938190.763 [Startup:StartupSatComms] Stopped 2019-10-01T13:56:30.763Z,1569938190.763 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-10-01T13:56:30.763Z,1569938190.763 [Startup](INFO): Completed Startup 2019-10-01T13:56:30.764Z,1569938190.764 [MissionManager](INFO): Startup is completed. 2019-10-01T13:56:30.764Z,1569938190.764 [MissionManager](INFO): Uninitializing Mission Startup 2019-10-01T13:56:30.764Z,1569938190.764 [Startup] Stopped 2019-10-01T13:56:30.764Z,1569938190.764 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-10-01T13:56:30.764Z,1569938190.764 [Startup:A.GoToSurface] Stopped 2019-10-01T13:56:30.764Z,1569938190.764 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-01T13:56:31.183Z,1569938191.183 [MissionManager](IMPORTANT): Started mission Default 2019-10-01T13:56:31.183Z,1569938191.183 [Default] Running Loop=1 2019-10-01T13:56:31.183Z,1569938191.183 [Default](DEBUG): Aggregate::initialize Default 2019-10-01T13:56:31.183Z,1569938191.183 [Default:B.GoToSurface] Running Loop=1 2019-10-01T13:56:31.183Z,1569938191.183 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-01T13:56:31.184Z,1569938191.184 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-01T13:56:31.184Z,1569938191.184 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-01T13:56:31.184Z,1569938191.184 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-01T13:56:31.185Z,1569938191.185 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-01T13:56:31.185Z,1569938191.185 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-01T13:56:31.185Z,1569938191.185 [Default:A.Wait] Running Loop=1 2019-10-01T13:56:31.186Z,1569938191.186 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-10-01T13:56:35.638Z,1569938195.638 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T13:56:35.638Z,1569938195.638 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999..99 2019-10-01T13:56:40.370Z,1569938200.370 [DataOverHttps](INFO): Sending 607 bytes from file Logs/20191001T135233/Express0001.lzma 2019-10-01T13:56:42.376Z,1569938202.376 [DataOverHttps](INFO): Moved sent file to Logs/20191001T135233/Express0001.lzma.bak 2019-10-01T13:56:42.377Z,1569938202.377 [DataOverHttps](INFO): SBD MOMSN=11835633 2019-10-01T13:56:44.503Z,1569938204.503 [Default:A.Wait](INFO): Done Waiting. 2019-10-01T13:56:44.503Z,1569938204.503 [Default:A.Wait] Stopped 2019-10-01T13:56:44.503Z,1569938204.503 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T13:56:44.901Z,1569938204.901 [Default:CheckIn] Running Loop=1 2019-10-01T13:56:44.901Z,1569938204.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T13:56:44.901Z,1569938204.901 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T13:56:45.316Z,1569938205.316 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-10-01T13:56:45.683Z,1569938205.683 [DVL_micro](ERROR): Failed to parse: :B,+00008,-0000,I 2019-10-01T13:56:53.823Z,1569938213.823 [CommandLine](IMPORTANT): got command failComponent 2019-10-01T13:56:53.823Z,1569938213.823 [CommandLine](IMPORTANT): Failed components: 2019-10-01T13:56:53.824Z,1569938213.824 [CommandLine](IMPORTANT): No failed Components. 2019-10-01T13:57:04.483Z,1569938224.483 [CommandLine](IMPORTANT): got command show variable par 2019-10-01T13:57:04.591Z,1569938224.591 [CommandLine](IMPORTANT): PAR_Licor.loadControl (none) 2019-10-01T13:57:04.591Z,1569938224.591 [CommandLine](IMPORTANT): PAR_Licor.ad (none) 2019-10-01T13:57:04.592Z,1569938224.592 [CommandLine](IMPORTANT): PAR_Licor.adRes (bit) 2019-10-01T13:57:04.592Z,1569938224.592 [CommandLine](IMPORTANT): PAR_Licor.adTimeout (millisecond) 2019-10-01T13:57:04.592Z,1569938224.592 [CommandLine](IMPORTANT): PAR_Licor.adVref (volt) 2019-10-01T13:57:04.613Z,1569938224.613 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup (bool) 2019-10-01T13:57:04.613Z,1569938224.613 [CommandLine](IMPORTANT): PAR_Licor.simulateHardware (bool) 2019-10-01T13:57:04.614Z,1569938224.614 [CommandLine](IMPORTANT): PAR_Licor.adcCal (microampere_per_count) 2019-10-01T13:57:04.614Z,1569938224.614 [CommandLine](IMPORTANT): PAR_Licor.darkCount (count) 2019-10-01T13:57:04.614Z,1569938224.614 [CommandLine](IMPORTANT): PAR_Licor.maxBound (micromole_per_second_per_square_meter) 2019-10-01T13:57:04.615Z,1569938224.615 [CommandLine](IMPORTANT): PAR_Licor.maxValidPitch (degree) 2019-10-01T13:57:04.615Z,1569938224.615 [CommandLine](IMPORTANT): PAR_Licor.minBound (micromole_per_second_per_square_meter) 2019-10-01T13:57:04.615Z,1569938224.615 [CommandLine](IMPORTANT): PAR_Licor.minValidPitch (degree) 2019-10-01T13:57:04.616Z,1569938224.616 [CommandLine](IMPORTANT): PAR_Licor.multiplier (micromole_per_second_per_square_meter_per_microampere) 2019-10-01T13:57:04.616Z,1569938224.616 [CommandLine](IMPORTANT): PAR_Licor.serial (none) 2019-10-01T13:57:04.735Z,1569938224.735 [CommandLine](IMPORTANT): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water (micromole_per_second_per_square_meter) 2019-10-01T13:57:04.736Z,1569938224.736 [CommandLine](IMPORTANT): PAR_Licor.adcCount (count) 2019-10-01T13:57:08.092Z,1569938228.092 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-10-01T13:57:12.519Z,1569938232.519 [CommandLine](IMPORTANT): got command report mod PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 2019-10-01T13:57:12.808Z,1569938232.808 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.247670 umol/s/m2 2019-10-01T13:57:13.242Z,1569938233.242 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.240409 umol/s/m2 2019-10-01T13:57:13.594Z,1569938233.594 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.244766 umol/s/m2 2019-10-01T13:57:14.003Z,1569938234.003 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.262192 umol/s/m2 2019-10-01T13:57:14.414Z,1569938234.414 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.240409 umol/s/m2 2019-10-01T13:57:14.804Z,1569938234.804 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.234601 umol/s/m2 2019-10-01T13:57:15.212Z,1569938235.212 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.247670 umol/s/m2 2019-10-01T13:57:15.635Z,1569938235.635 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.259287 umol/s/m2 2019-10-01T13:57:16.025Z,1569938236.025 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.250575 umol/s/m2 2019-10-01T13:57:16.439Z,1569938236.439 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.246218 umol/s/m2 2019-10-01T13:57:16.820Z,1569938236.820 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.244766 umol/s/m2 2019-10-01T13:57:17.264Z,1569938237.264 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 6.732157 umol/s/m2 2019-10-01T13:57:17.653Z,1569938237.653 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.060990 umol/s/m2 2019-10-01T13:57:18.068Z,1569938238.068 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.062442 umol/s/m2 2019-10-01T13:57:18.483Z,1569938238.483 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.066799 umol/s/m2 2019-10-01T13:57:18.853Z,1569938238.853 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.059538 umol/s/m2 2019-10-01T13:57:19.255Z,1569938239.255 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.097294 umol/s/m2 2019-10-01T13:57:19.668Z,1569938239.668 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.091485 umol/s/m2 2019-10-01T13:57:20.056Z,1569938240.056 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.094390 umol/s/m2 2019-10-01T13:57:20.461Z,1569938240.461 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.082772 umol/s/m2 2019-10-01T13:57:20.888Z,1569938240.888 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.072607 umol/s/m2 2019-10-01T13:57:21.399Z,1569938241.399 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.221532 umol/s/m2 2019-10-01T13:57:21.705Z,1569938241.705 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.257835 umol/s/m2 2019-10-01T13:57:22.526Z,1569938242.526 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.234601 umol/s/m2 2019-10-01T13:57:22.905Z,1569938242.905 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.263644 umol/s/m2 2019-10-01T13:57:23.328Z,1569938243.328 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.244766 umol/s/m2 2019-10-01T13:57:23.724Z,1569938243.724 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.241862 umol/s/m2 2019-10-01T13:57:24.100Z,1569938244.100 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.253479 umol/s/m2 2019-10-01T13:57:24.509Z,1569938244.509 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.247670 umol/s/m2 2019-10-01T13:57:24.899Z,1569938244.899 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.243314 umol/s/m2 2019-10-01T13:57:25.310Z,1569938245.310 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.244766 umol/s/m2 2019-10-01T13:57:25.729Z,1569938245.729 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.254931 umol/s/m2 2019-10-01T13:57:26.122Z,1569938246.122 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.237505 umol/s/m2 2019-10-01T13:57:26.534Z,1569938246.534 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.254931 umol/s/m2 2019-10-01T13:57:26.921Z,1569938246.921 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.237505 umol/s/m2 2019-10-01T13:57:27.337Z,1569938247.337 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.228792 umol/s/m2 2019-10-01T13:57:27.753Z,1569938247.753 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.238957 umol/s/m2 2019-10-01T13:57:28.572Z,1569938248.572 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.265096 umol/s/m2 2019-10-01T13:57:28.951Z,1569938248.951 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.247670 umol/s/m2 2019-10-01T13:57:29.356Z,1569938249.356 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.240409 umol/s/m2 2019-10-01T13:57:29.766Z,1569938249.766 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.246218 umol/s/m2 2019-10-01T13:57:30.152Z,1569938250.152 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.257835 umol/s/m2 2019-10-01T13:57:30.558Z,1569938250.558 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.256383 umol/s/m2 2019-10-01T13:57:30.989Z,1569938250.989 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.249122 umol/s/m2 2019-10-01T13:57:31.383Z,1569938251.383 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 8.290313 umol/s/m2 2019-10-01T13:57:31.793Z,1569938251.793 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 20.486902 umol/s/m2 2019-10-01T13:57:32.176Z,1569938252.176 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 104.694054 umol/s/m2 2019-10-01T13:57:32.590Z,1569938252.590 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 358.545471 umol/s/m2 2019-10-01T13:57:33.017Z,1569938253.017 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 350.628357 umol/s/m2 2019-10-01T13:57:33.445Z,1569938253.445 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 412.948730 umol/s/m2 2019-10-01T13:57:33.825Z,1569938253.825 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 423.301117 umol/s/m2 2019-10-01T13:57:34.269Z,1569938254.269 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 427.775177 umol/s/m2 2019-10-01T13:57:34.763Z,1569938254.763 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 402.275482 umol/s/m2 2019-10-01T13:57:35.175Z,1569938255.175 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 403.910583 umol/s/m2 2019-10-01T13:57:35.479Z,1569938255.479 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 455.180115 umol/s/m2 2019-10-01T13:57:35.906Z,1569938255.906 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 43.599289 umol/s/m2 2019-10-01T13:57:36.267Z,1569938256.267 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.481466 umol/s/m2 2019-10-01T13:57:36.645Z,1569938256.645 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.382720 umol/s/m2 2019-10-01T13:57:37.060Z,1569938257.060 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.344965 umol/s/m2 2019-10-01T13:57:37.462Z,1569938257.462 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.307208 umol/s/m2 2019-10-01T13:57:37.877Z,1569938257.877 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.298495 umol/s/m2 2019-10-01T13:57:38.664Z,1569938258.664 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.318825 umol/s/m2 2019-10-01T13:57:39.072Z,1569938259.072 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.275261 umol/s/m2 2019-10-01T13:57:39.464Z,1569938259.464 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.278165 umol/s/m2 2019-10-01T13:57:39.859Z,1569938259.859 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.262192 umol/s/m2 2019-10-01T13:57:40.272Z,1569938260.272 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.272357 umol/s/m2 2019-10-01T13:57:40.657Z,1569938260.657 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.269453 umol/s/m2 2019-10-01T13:57:41.079Z,1569938261.079 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.259287 umol/s/m2 2019-10-01T13:57:41.473Z,1569938261.473 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.273809 umol/s/m2 2019-10-01T13:57:41.883Z,1569938261.883 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.262192 umol/s/m2 2019-10-01T13:57:42.274Z,1569938262.274 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.257835 umol/s/m2 2019-10-01T13:57:42.684Z,1569938262.684 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.254931 umol/s/m2 2019-10-01T13:57:43.538Z,1569938263.538 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.257835 umol/s/m2 2019-10-01T13:57:43.920Z,1569938263.920 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.254931 umol/s/m2 2019-10-01T13:57:44.308Z,1569938264.308 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.260739 umol/s/m2 2019-10-01T13:57:44.724Z,1569938264.724 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.259287 umol/s/m2 2019-10-01T13:57:45.116Z,1569938265.116 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.256383 umol/s/m2 2019-10-01T13:57:45.509Z,1569938265.509 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.257835 umol/s/m2 2019-10-01T13:57:45.956Z,1569938265.956 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.256383 umol/s/m2 2019-10-01T13:57:46.325Z,1569938266.325 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.249122 umol/s/m2 2019-10-01T13:57:46.732Z,1569938266.732 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.259287 umol/s/m2 2019-10-01T13:57:47.120Z,1569938267.120 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.272357 umol/s/m2 2019-10-01T13:57:47.533Z,1569938267.533 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.273809 umol/s/m2 2019-10-01T13:57:47.939Z,1569938267.939 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.256383 umol/s/m2 2019-10-01T13:57:48.490Z,1569938268.490 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.265096 umol/s/m2 2019-10-01T13:57:48.784Z,1569938268.784 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.285426 umol/s/m2 2019-10-01T13:57:49.193Z,1569938269.193 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.273809 umol/s/m2 2019-10-01T13:57:49.587Z,1569938269.587 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.260739 umol/s/m2 2019-10-01T13:57:49.972Z,1569938269.972 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.279617 umol/s/m2 2019-10-01T13:57:50.375Z,1569938270.375 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.250575 umol/s/m2 2019-10-01T13:57:50.792Z,1569938270.792 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.265096 umol/s/m2 2019-10-01T13:57:51.176Z,1569938271.176 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.307208 umol/s/m2 2019-10-01T13:57:51.574Z,1569938271.574 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.278165 umol/s/m2 2019-10-01T13:57:51.990Z,1569938271.990 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.266548 umol/s/m2 2019-10-01T13:57:52.376Z,1569938272.376 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.289783 umol/s/m2 2019-10-01T13:57:52.792Z,1569938272.792 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.283974 umol/s/m2 2019-10-01T13:57:53.190Z,1569938273.190 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.263644 umol/s/m2 2019-10-01T13:57:53.624Z,1569938273.624 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.279617 umol/s/m2 2019-10-01T13:57:54.016Z,1569938274.016 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.269453 umol/s/m2 2019-10-01T13:57:54.401Z,1569938274.401 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.283974 umol/s/m2 2019-10-01T13:57:54.820Z,1569938274.820 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.256383 umol/s/m2 2019-10-01T13:57:55.224Z,1569938275.224 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 7.254931 umol/s/m2 2019-10-01T13:57:55.386Z,1569938275.386 [CommandLine](IMPORTANT): got command report clear 2019-10-01T13:58:01.232Z,1569938281.232 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T13:58:01.232Z,1569938281.232 [DVL_micro](ERROR): Failed to parse: :BI,00020,-00156,+00000,I 2019-10-01T13:58:01.717Z,1569938281.717 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-10-01T13:58:14.645Z,1569938294.645 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-10-01T13:58:26.286Z,1569938306.286 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-01T13:58:27.097Z,1569938307.097 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:29.925Z,1569938309.925 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:32.753Z,1569938312.753 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:35.985Z,1569938315.985 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:38.866Z,1569938318.866 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:42.045Z,1569938322.045 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:44.877Z,1569938324.877 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:45.710Z,1569938325.710 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-10-01T13:58:45.710Z,1569938325.710 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T13:58:45.720Z,1569938325.720 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T13:58:46.112Z,1569938326.112 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T13:58:46.112Z,1569938326.112 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-10-01T13:58:47.701Z,1569938327.701 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:50.129Z,1569938330.129 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:52.953Z,1569938332.953 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:56.195Z,1569938336.195 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:58:59.025Z,1569938339.025 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:01.845Z,1569938341.845 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:05.073Z,1569938345.073 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:07.905Z,1569938347.905 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:10.449Z,1569938350.449 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T13:59:10.741Z,1569938350.741 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:13.969Z,1569938353.969 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:16.813Z,1569938356.813 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:20.026Z,1569938360.026 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:22.853Z,1569938362.853 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:26.081Z,1569938366.081 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:26.880Z,1569938366.880 [DVL_micro](ERROR): Failed to parse: :BI,-00144,-00273,-00260,+00000,I 2019-10-01T13:59:28.913Z,1569938368.913 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:32.141Z,1569938372.141 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:34.969Z,1569938374.969 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:36.981Z,1569938376.981 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-10-01T13:59:38.197Z,1569938378.197 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:41.025Z,1569938381.025 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:44.278Z,1569938384.278 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:47.093Z,1569938387.093 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:50.317Z,1569938390.317 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:53.154Z,1569938393.154 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:55.981Z,1569938395.981 [NAL9602](DEBUG): Fix Requested 2019-10-01T13:59:58.889Z,1569938398.889 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:02.053Z,1569938402.053 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:04.130Z,1569938404.130 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-10-01T14:00:04.866Z,1569938404.866 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:04.941Z,1569938404.941 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T14:00:08.097Z,1569938408.097 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:09.703Z,1569938409.703 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T14:00:09.703Z,1569938409.703 [DVL_micro](ERROR): Failed to parse: :BI,-00112,+00053,00000,I 2019-10-01T14:00:10.930Z,1569938410.930 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:14.162Z,1569938414.162 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:16.994Z,1569938416.994 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:20.217Z,1569938420.217 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:23.045Z,1569938423.045 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:26.281Z,1569938426.281 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:29.121Z,1569938429.121 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:32.353Z,1569938432.353 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:35.170Z,1569938435.170 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:37.999Z,1569938437.999 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:41.241Z,1569938441.241 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:44.053Z,1569938444.053 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:44.853Z,1569938444.853 [DVL_micro](ERROR): Failed to parse: :WI,+00073,+00020,-00220,+000I,+00073-00220,+00000,I 2019-10-01T14:00:46.881Z,1569938446.881 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:48.153Z,1569938448.153 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-10-01T14:00:50.121Z,1569938450.121 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:52.945Z,1569938452.945 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:56.177Z,1569938456.177 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:00:59.001Z,1569938459.001 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:02.270Z,1569938462.270 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:04.677Z,1569938464.677 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-10-01T14:01:04.678Z,1569938464.678 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-10-01T14:01:04.678Z,1569938464.678 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-10-01T14:01:04.682Z,1569938464.682 [BPC1](INFO): Received data from all battery sticks. 2019-10-01T14:01:05.085Z,1569938465.085 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:08.301Z,1569938468.301 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:11.137Z,1569938471.137 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:14.357Z,1569938474.357 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:17.192Z,1569938477.192 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:20.421Z,1569938480.421 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:23.245Z,1569938483.245 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:26.073Z,1569938486.073 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:29.305Z,1569938489.305 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:32.129Z,1569938492.129 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:34.981Z,1569938494.981 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:36.981Z,1569938496.981 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:40.234Z,1569938500.234 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:43.045Z,1569938503.045 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:45.091Z,1569938505.091 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-01T13:56:44.9Z 2019-10-01T14:01:45.091Z,1569938505.091 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T14:01:45.091Z,1569938505.091 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-01T14:01:45.485Z,1569938505.485 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-01T14:01:46.342Z,1569938506.342 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:46.793Z,1569938506.793 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-10-01T14:01:46.794Z,1569938506.794 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T14:01:46.824Z,1569938506.824 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T14:01:47.213Z,1569938507.213 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T14:01:47.213Z,1569938507.213 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-10-01T14:01:49.169Z,1569938509.169 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:50.961Z,1569938510.961 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20191001T135233/Courier0004.lzma 2019-10-01T14:01:51.989Z,1569938511.989 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:52.967Z,1569938512.967 [DataOverHttps](INFO): Moved sent file to Logs/20191001T135233/Courier0004.lzma.bak 2019-10-01T14:01:52.967Z,1569938512.967 [DataOverHttps](INFO): SBD MOMSN=11835658 2019-10-01T14:01:55.269Z,1569938515.269 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:01:58.053Z,1569938518.053 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:01.289Z,1569938521.289 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:04.113Z,1569938524.113 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:07.337Z,1569938527.337 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:10.173Z,1569938530.173 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:10.563Z,1569938530.563 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-10-01T14:02:10.563Z,1569938530.563 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.8,0000.0,10 2019-10-01T14:02:13.013Z,1569938533.013 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:15.017Z,1569938535.017 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:17.033Z,1569938537.033 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:20.270Z,1569938540.270 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:20.667Z,1569938540.667 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T14:02:20.668Z,1569938540.668 [DVL_micro](ERROR): Failed to parse: :BI,00004,-00187,+00000,I 2019-10-01T14:02:21.730Z,1569938541.730 [DataOverHttps](INFO): Sending 562 bytes from file Logs/20191001T135233/Express0005.lzma 2019-10-01T14:02:23.117Z,1569938543.117 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:23.736Z,1569938543.736 [DataOverHttps](INFO): Moved sent file to Logs/20191001T135233/Express0005.lzma.bak 2019-10-01T14:02:23.736Z,1569938543.736 [DataOverHttps](INFO): SBD MOMSN=11835660 2019-10-01T14:02:26.330Z,1569938546.330 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:26.355Z,1569938546.355 [Default:CheckIn:Read_Iridium] Stopped 2019-10-01T14:02:26.355Z,1569938546.355 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-01T14:02:26.355Z,1569938546.355 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-01T14:02:29.157Z,1569938549.157 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:32.389Z,1569938552.389 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:35.222Z,1569938555.222 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:38.453Z,1569938558.453 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:41.281Z,1569938561.281 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:44.532Z,1569938564.532 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:47.348Z,1569938567.348 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:50.597Z,1569938570.597 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:53.413Z,1569938573.413 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:56.229Z,1569938576.229 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:02:59.053Z,1569938579.053 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:01.073Z,1569938581.073 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:03.094Z,1569938583.094 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:06.325Z,1569938586.325 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:09.164Z,1569938589.164 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:12.388Z,1569938592.388 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:15.213Z,1569938595.213 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:18.457Z,1569938598.457 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:21.273Z,1569938601.273 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:03:24.092Z,1569938604.092 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-10-01T14:03:24.092Z,1569938604.092 [NAL9602] Data Fault, FailCount= 1 2019-10-01T14:03:24.092Z,1569938604.092 [NAL9602](ERROR): Data Fault 2019-10-01T14:03:24.142Z,1569938604.142 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-01T14:03:24.495Z,1569938604.495 [NAL9602](INFO): Powering down 2019-10-01T14:03:25.337Z,1569938605.337 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-01T14:03:25.338Z,1569938605.338 [NAL9602] No Fault, FailCount= 1 2019-10-01T14:03:54.815Z,1569938634.815 [NAL9602](INFO): Powering up NAL9602 2019-10-01T14:04:05.701Z,1569938645.701 [NAL9602](INFO): NAL9602 initialized 2019-10-01T14:04:06.525Z,1569938646.525 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:08.965Z,1569938648.965 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:10.973Z,1569938650.973 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:12.989Z,1569938652.989 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:16.233Z,1569938656.233 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:19.061Z,1569938659.061 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:22.282Z,1569938662.282 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:25.105Z,1569938665.105 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:28.333Z,1569938668.333 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:31.176Z,1569938671.176 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:34.009Z,1569938674.009 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:36.016Z,1569938676.016 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:38.033Z,1569938678.033 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:41.265Z,1569938681.265 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:44.105Z,1569938684.105 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:47.325Z,1569938687.325 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:47.754Z,1569938687.754 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-10-01T14:04:47.754Z,1569938687.754 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-01T14:04:47.764Z,1569938687.764 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-01T14:04:48.179Z,1569938688.179 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-01T14:04:48.179Z,1569938688.179 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-10-01T14:04:50.153Z,1569938690.153 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:53.389Z,1569938693.389 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:56.221Z,1569938696.221 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:04:59.057Z,1569938699.057 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:02.273Z,1569938702.273 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:05.101Z,1569938705.101 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:08.354Z,1569938708.354 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:11.162Z,1569938711.162 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:14.453Z,1569938714.453 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:17.222Z,1569938717.222 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:20.049Z,1569938720.049 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:22.085Z,1569938722.085 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:24.097Z,1569938724.097 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:27.329Z,1569938727.329 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:30.149Z,1569938730.149 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:33.381Z,1569938733.381 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:36.205Z,1569938736.205 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:39.473Z,1569938739.473 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:42.281Z,1569938742.281 [DVL_micro](ERROR): only read 1 of 4 data items 2019-10-01T14:05:42.282Z,1569938742.282 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,,+9999.99,+9999.99 2019-10-01T14:05:42.293Z,1569938742.293 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:45.097Z,1569938745.097 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:47.125Z,1569938747.125 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:49.137Z,1569938749.137 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:52.365Z,1569938752.365 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:55.201Z,1569938755.201 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:05:58.430Z,1569938758.430 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:01.261Z,1569938761.261 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:04.493Z,1569938764.493 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:07.333Z,1569938767.333 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:10.150Z,1569938770.150 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:12.181Z,1569938772.181 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:14.985Z,1569938774.985 [DVL_micro](ERROR): Failed to parse:00000000,+21.9,0000.0,00 2019-10-01T14:06:15.414Z,1569938775.414 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:18.229Z,1569938778.229 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:21.461Z,1569938781.461 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:24.289Z,1569938784.289 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:25.092Z,1569938785.092 [DVL_micro](ERROR): only read 0 of 4 data items 2019-10-01T14:06:25.093Z,1569938785.093 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.999,+9999.99 2019-10-01T14:06:27.541Z,1569938787.542 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:30.345Z,1569938790.345 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:33.177Z,1569938793.177 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:35.201Z,1569938795.201 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:38.429Z,1569938798.429 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:41.257Z,1569938801.257 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:44.490Z,1569938804.490 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:47.318Z,1569938807.318 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:50.557Z,1569938810.557 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:53.378Z,1569938813.378 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:56.207Z,1569938816.207 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:06:58.225Z,1569938818.225 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:00.253Z,1569938820.253 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:03.481Z,1569938823.481 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:06.309Z,1569938826.309 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:07.911Z,1569938827.911 [DVL_micro](ERROR): only read 3 of 4 data items 2019-10-01T14:07:07.911Z,1569938827.911 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2019-10-01T14:07:09.545Z,1569938829.545 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:12.369Z,1569938832.369 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:15.597Z,1569938835.597 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:18.432Z,1569938838.432 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:21.261Z,1569938841.261 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:23.281Z,1569938843.281 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:24.863Z,1569938844.863 [CommandLine](IMPORTANT): got command restart system 2019-10-01T14:07:26.509Z,1569938846.509 [NAL9602](DEBUG): Fix Requested 2019-10-01T14:07:26.922Z,1569938846.922 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-10-01T14:07:26.923Z,1569938846.923 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:26.923Z,1569938846.923 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:26.932Z,1569938846.932 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-01T14:07:26.932Z,1569938846.932 [Default:CheckIn:C.Wait] Stopped 2019-10-01T14:07:26.932Z,1569938846.932 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-01T14:07:26.932Z,1569938846.932 [Default:CheckIn:D] Running Loop=1 2019-10-01T14:07:27.097Z,1569938847.097 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-10-01T14:07:27.098Z,1569938847.098 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.103Z,1569938847.103 [CommandLine](INFO): Join timeout helper Thread ID is 6034 2019-10-01T14:07:27.103Z,1569938847.103 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-10-01T14:07:27.103Z,1569938847.103 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.104Z,1569938847.104 [NavChartDb](INFO): Join timeout helper Thread ID is 6035 2019-10-01T14:07:27.355Z,1569938847.355 [Default:CheckIn:D] Stopped 2019-10-01T14:07:27.355Z,1569938847.355 [Default:CheckIn:E] Running Loop=1 2019-10-01T14:07:27.422Z,1569938847.422 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:27.422Z,1569938847.422 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.441Z,1569938847.441 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-10-01T14:07:27.441Z,1569938847.441 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.442Z,1569938847.442 [Radio_Surface](INFO): Join timeout helper Thread ID is 6036 2019-10-01T14:07:27.450Z,1569938847.450 [Radio_Surface](INFO): Powering down 2019-10-01T14:07:27.451Z,1569938847.451 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:27.451Z,1569938847.451 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.461Z,1569938847.461 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-10-01T14:07:27.462Z,1569938847.462 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.462Z,1569938847.462 [DataOverHttps](INFO): Join timeout helper Thread ID is 6037 2019-10-01T14:07:27.751Z,1569938847.751 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.936192 min 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn:E] Stopped 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn] Stopped 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn](INFO): Running loop #2 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn] Running Loop=2 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-01T14:07:27.752Z,1569938847.752 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-01T14:07:27.782Z,1569938847.782 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:27.782Z,1569938847.782 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.790Z,1569938847.790 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-10-01T14:07:27.790Z,1569938847.790 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:27.790Z,1569938847.790 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6038 2019-10-01T14:07:28.046Z,1569938848.046 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:28.046Z,1569938848.046 [WetLabsBB2FL](INFO): Powering down 2019-10-01T14:07:28.047Z,1569938848.047 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:28.058Z,1569938848.058 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-10-01T14:07:28.058Z,1569938848.058 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:28.059Z,1569938848.059 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6039 2019-10-01T14:07:28.958Z,1569938848.958 [CTD_Seabird](INFO): Powering down 2019-10-01T14:07:28.970Z,1569938848.970 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:28.970Z,1569938848.970 [CTD_Seabird](INFO): Powering down 2019-10-01T14:07:28.982Z,1569938848.982 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.002Z,1569938849.002 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-10-01T14:07:29.002Z,1569938849.002 [logger ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.003Z,1569938849.003 [logger](INFO): Join timeout helper Thread ID is 6040 2019-10-01T14:07:29.012Z,1569938849.012 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:29.012Z,1569938849.012 [logger ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.030Z,1569938849.030 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-10-01T14:07:29.030Z,1569938849.030 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.030Z,1569938849.030 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-10-01T14:07:29.030Z,1569938849.030 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.031Z,1569938849.031 [controlThread](INFO): Join timeout helper Thread ID is 6041 2019-10-01T14:07:29.302Z,1569938849.302 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-01T14:07:29.302Z,1569938849.302 [controlThread](DEBUG): Uninitializing ControlThread 2019-10-01T14:07:29.302Z,1569938849.302 [Aanderaa_O2](INFO): Powering down 2019-10-01T14:07:29.324Z,1569938849.324 [AHRS_M2](INFO): Powering down 2019-10-01T14:07:29.466Z,1569938849.466 [DVL_micro](INFO): Powering down 2019-10-01T14:07:29.466Z,1569938849.466 [NAL9602](INFO): Powering down 2019-10-01T14:07:29.468Z,1569938849.468 [DAT](INFO): Powering down 2019-10-01T14:07:29.586Z,1569938849.586 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-10-01T14:07:29.587Z,1569938849.587 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-10-01T14:07:29.588Z,1569938849.588 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-10-01T14:07:29.588Z,1569938849.588 [MissionManager](INFO): Uninitializing Mission Default 2019-10-01T14:07:29.588Z,1569938849.588 [Default] Stopped 2019-10-01T14:07:29.588Z,1569938849.588 [Default](DEBUG): Aggregate::uninitialize Default 2019-10-01T14:07:29.588Z,1569938849.588 [Default:B.GoToSurface] Stopped 2019-10-01T14:07:29.588Z,1569938849.588 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-01T14:07:29.589Z,1569938849.589 [Default:CheckIn] Stopped 2019-10-01T14:07:29.589Z,1569938849.589 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-01T14:07:29.589Z,1569938849.589 [Default:CheckIn:Read_GPS] Stopped 2019-10-01T14:07:29.591Z,1569938849.591 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-10-01T14:07:29.592Z,1569938849.592 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-10-01T14:07:29.592Z,1569938849.592 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-10-01T14:07:29.592Z,1569938849.592 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-10-01T14:07:29.592Z,1569938849.592 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-10-01T14:07:29.593Z,1569938849.593 [BuoyancyServo](INFO): Powering down 2019-10-01T14:07:29.606Z,1569938849.606 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-10-01T14:07:29.606Z,1569938849.606 [ElevatorServo](INFO): Powering down 2019-10-01T14:07:29.607Z,1569938849.607 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-10-01T14:07:29.607Z,1569938849.607 [MassServo](INFO): Powering down 2019-10-01T14:07:29.608Z,1569938849.608 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-10-01T14:07:29.608Z,1569938849.608 [RudderServo](INFO): Powering down 2019-10-01T14:07:29.608Z,1569938849.608 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-10-01T14:07:29.609Z,1569938849.609 [ThrusterServo](INFO): Powering down 2019-10-01T14:07:29.610Z,1569938849.610 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-10-01T14:07:29.610Z,1569938849.610 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-10-01T14:07:29.610Z,1569938849.610 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-10-01T14:07:29.610Z,1569938849.610 [CBIT](DEBUG): Powering off loads. 2019-10-01T14:07:29.621Z,1569938849.621 [CBIT](DEBUG): Disabling WDT. 2019-10-01T14:07:29.633Z,1569938849.633 [CBIT](DEBUG): Opening all GF detection circuits. 2019-10-01T14:07:29.634Z,1569938849.634 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.678Z,1569938849.678 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.685Z,1569938849.685 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.748Z,1569938849.748 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.754Z,1569938849.754 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.805Z,1569938849.805 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-01T14:07:29.861Z,1569938849.861 [logger ThreadHandler](INFO): Thread cancelled.