2020-06-03T17:49:16.077Z,1591206556.077 [Supervisor](DEBUG): Initializing supervisor. 2020-06-03T17:49:16.089Z,1591206556.089 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-06-03T17:49:16.089Z,1591206556.089 [SyncHandler](INFO): Protected caller Thread ID is 820 2020-06-03T17:49:16.090Z,1591206556.090 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-06-03T17:49:16.101Z,1591206556.101 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-06-03T17:49:16.101Z,1591206556.101 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 821 2020-06-03T17:49:16.104Z,1591206556.104 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-06-03T17:49:16.141Z,1591206556.141 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-06-03T17:49:16.153Z,1591206556.153 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-06-03T17:49:16.153Z,1591206556.153 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 822 2020-06-03T17:49:16.154Z,1591206556.154 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-06-03T17:49:16.165Z,1591206556.165 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-06-03T17:49:16.165Z,1591206556.165 [logger ThreadHandler](INFO): Protected caller Thread ID is 823 2020-06-03T17:49:16.167Z,1591206556.167 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-06-03T17:49:16.168Z,1591206556.168 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-06-03T17:49:16.175Z,1591206556.175 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-06-03T17:49:16.836Z,1591206556.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-06-03T17:49:16.838Z,1591206556.838 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-06-03T17:49:18.044Z,1591206558.044 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-06-03T17:49:18.046Z,1591206558.046 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-06-03T17:49:18.295Z,1591206558.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-06-03T17:49:18.297Z,1591206558.297 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-06-03T17:49:19.208Z,1591206559.208 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-06-03T17:49:19.209Z,1591206559.209 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-06-03T17:49:19.377Z,1591206559.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-06-03T17:49:19.379Z,1591206559.379 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-06-03T17:49:19.511Z,1591206559.511 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-06-03T17:49:20.112Z,1591206560.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-06-03T17:49:20.114Z,1591206560.114 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-06-03T17:49:20.392Z,1591206560.392 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-06-03T17:49:20.393Z,1591206560.393 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-06-03T17:49:20.579Z,1591206560.579 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-06-03T17:49:20.581Z,1591206560.581 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-06-03T17:49:20.970Z,1591206560.970 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-06-03T17:49:20.970Z,1591206560.970 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-06-03T17:49:21.524Z,1591206561.524 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-06-03T17:49:21.524Z,1591206561.524 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-06-03T17:49:21.940Z,1591206561.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-06-03T17:49:21.940Z,1591206561.940 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-06-03T17:49:22.042Z,1591206562.042 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-06-03T17:49:22.042Z,1591206562.042 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-06-03T17:49:22.237Z,1591206562.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-06-03T17:49:22.239Z,1591206562.239 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-06-03T17:49:22.456Z,1591206562.456 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-06-03T17:49:22.456Z,1591206562.456 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-06-03T17:49:22.683Z,1591206562.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-06-03T17:49:22.685Z,1591206562.685 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2020-06-03T17:49:22.689Z,1591206562.689 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2020-06-03T17:49:22.788Z,1591206562.788 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2020-06-03T17:49:22.929Z,1591206562.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2020-06-03T17:49:23.014Z,1591206563.014 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2020-06-03T17:49:23.097Z,1591206563.097 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2020-06-03T17:49:23.202Z,1591206563.202 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2020-06-03T17:49:23.388Z,1591206563.388 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2020-06-03T17:49:23.619Z,1591206563.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-06-03T17:49:23.620Z,1591206563.620 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2020-06-03T17:49:23.731Z,1591206563.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2020-06-03T17:49:23.826Z,1591206563.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2020-06-03T17:49:23.924Z,1591206563.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2020-06-03T17:49:24.017Z,1591206564.017 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-06-03T17:49:24.028Z,1591206564.028 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-06-03T17:49:24.060Z,1591206564.060 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-06-03T17:49:24.060Z,1591206564.060 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-06-03T17:49:24.116Z,1591206564.116 [DepthRateCalculator] Loaded 2020-06-03T17:49:24.116Z,1591206564.116 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-06-03T17:49:24.123Z,1591206564.123 [PitchRateCalculator] Loaded 2020-06-03T17:49:24.123Z,1591206564.123 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-06-03T17:49:24.139Z,1591206564.139 [SpeedCalculator] Loaded 2020-06-03T17:49:24.139Z,1591206564.139 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-06-03T17:49:24.162Z,1591206564.162 [TempGradientCalculator] Loaded 2020-06-03T17:49:24.162Z,1591206564.162 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-06-03T17:49:24.168Z,1591206564.168 [YawRateCalculator] Loaded 2020-06-03T17:49:24.168Z,1591206564.168 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-06-03T17:49:24.209Z,1591206564.209 [ElevatorOffsetCalculator] Loaded 2020-06-03T17:49:24.209Z,1591206564.209 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-06-03T17:49:24.209Z,1591206564.209 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-06-03T17:49:24.210Z,1591206564.210 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-06-03T17:49:24.342Z,1591206564.342 [VerticalControl](DEBUG): Construct VerticalControl. 2020-06-03T17:49:24.631Z,1591206564.631 [VerticalControl] Loaded 2020-06-03T17:49:24.631Z,1591206564.631 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-06-03T17:49:24.632Z,1591206564.632 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-06-03T17:49:24.722Z,1591206564.722 [HorizontalControl] Loaded 2020-06-03T17:49:24.722Z,1591206564.722 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-06-03T17:49:24.723Z,1591206564.723 [SpeedControl](DEBUG): Construct SpeedControl. 2020-06-03T17:49:24.742Z,1591206564.742 [SpeedControl] Loaded 2020-06-03T17:49:24.743Z,1591206564.743 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-06-03T17:49:24.743Z,1591206564.743 [LoopControl](DEBUG): Construct LoopControl. 2020-06-03T17:49:24.744Z,1591206564.744 [LoopControl] Loaded 2020-06-03T17:49:24.744Z,1591206564.744 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-06-03T17:49:24.745Z,1591206564.745 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-06-03T17:49:24.745Z,1591206564.745 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-06-03T17:49:25.277Z,1591206565.277 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-06-03T17:49:25.278Z,1591206565.278 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-06-03T17:49:25.299Z,1591206565.299 [NavChart] Loaded 2020-06-03T17:49:25.300Z,1591206565.300 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-06-03T17:49:25.304Z,1591206565.304 [UniversalFixResidualReporter] Loaded 2020-06-03T17:49:25.304Z,1591206565.304 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-06-03T17:49:25.305Z,1591206565.305 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-06-03T17:49:25.305Z,1591206565.305 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-06-03T17:49:25.433Z,1591206565.433 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-06-03T17:49:25.433Z,1591206565.433 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-06-03T17:49:25.975Z,1591206565.975 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-06-03T17:49:25.980Z,1591206565.980 [AHRS_M2](INFO): created writer for : platform_orientation 2020-06-03T17:49:25.982Z,1591206565.982 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-06-03T17:49:25.987Z,1591206565.987 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-06-03T17:49:25.988Z,1591206565.988 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-06-03T17:49:25.993Z,1591206565.993 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-06-03T17:49:25.993Z,1591206565.993 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-06-03T17:49:25.999Z,1591206565.999 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-06-03T17:49:26.178Z,1591206566.178 [AHRS_M2] Loaded 2020-06-03T17:49:26.179Z,1591206566.179 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-06-03T17:49:26.326Z,1591206566.326 [DataOverHttps] Loaded 2020-06-03T17:49:26.327Z,1591206566.327 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-06-03T17:49:26.328Z,1591206566.328 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408244E0 2020-06-03T17:49:26.328Z,1591206566.328 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 905 2020-06-03T17:49:26.342Z,1591206566.342 [Depth_Keller] Loaded 2020-06-03T17:49:26.343Z,1591206566.343 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-06-03T17:49:26.347Z,1591206566.347 [DropWeight] Loaded 2020-06-03T17:49:26.348Z,1591206566.348 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-06-03T17:49:26.395Z,1591206566.395 [DVL_micro] Loaded 2020-06-03T17:49:26.395Z,1591206566.395 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2020-06-03T17:49:26.494Z,1591206566.494 [NAL9602] Loaded 2020-06-03T17:49:26.494Z,1591206566.494 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-06-03T17:49:26.543Z,1591206566.543 [Onboard] Loaded 2020-06-03T17:49:26.544Z,1591206566.544 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2020-06-03T17:49:26.545Z,1591206566.545 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408544E0 2020-06-03T17:49:26.545Z,1591206566.545 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 906 2020-06-03T17:49:26.549Z,1591206566.549 [Radio_Surface] Loaded 2020-06-03T17:49:26.549Z,1591206566.549 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-06-03T17:49:26.550Z,1591206566.550 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0 2020-06-03T17:49:26.550Z,1591206566.550 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 907 2020-06-03T17:49:26.688Z,1591206566.688 [DAT] Loaded 2020-06-03T17:49:26.688Z,1591206566.688 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-06-03T17:49:28.220Z,1591206568.220 [BPC1] Loaded 2020-06-03T17:49:28.221Z,1591206568.221 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-06-03T17:49:28.221Z,1591206568.221 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-06-03T17:49:28.222Z,1591206568.222 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-06-03T17:49:28.350Z,1591206568.350 [BuoyancyServo] Loaded 2020-06-03T17:49:28.350Z,1591206568.350 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-06-03T17:49:28.363Z,1591206568.363 [ElevatorServo] Loaded 2020-06-03T17:49:28.363Z,1591206568.363 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-06-03T17:49:28.375Z,1591206568.375 [MassServo] Loaded 2020-06-03T17:49:28.376Z,1591206568.376 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-06-03T17:49:28.388Z,1591206568.388 [RudderServo] Loaded 2020-06-03T17:49:28.388Z,1591206568.388 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-06-03T17:49:28.399Z,1591206568.399 [ThrusterServo] Loaded 2020-06-03T17:49:28.399Z,1591206568.399 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-06-03T17:49:28.400Z,1591206568.400 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-06-03T17:49:28.401Z,1591206568.401 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-06-03T17:49:28.524Z,1591206568.524 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-06-03T17:49:28.525Z,1591206568.525 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-06-03T17:49:28.566Z,1591206568.566 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-06-03T17:49:28.567Z,1591206568.567 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-06-03T17:49:28.927Z,1591206568.927 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-06-03T17:49:28.928Z,1591206568.928 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-06-03T17:49:29.198Z,1591206569.198 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-06-03T17:49:29.203Z,1591206569.203 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-06-03T17:49:29.204Z,1591206569.204 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-06-03T17:49:29.209Z,1591206569.209 [CTD_Seabird](INFO): created writer for : depth 2020-06-03T17:49:29.209Z,1591206569.209 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-06-03T17:49:29.214Z,1591206569.214 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-06-03T17:49:29.215Z,1591206569.215 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-06-03T17:49:29.220Z,1591206569.220 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-06-03T17:49:29.221Z,1591206569.221 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-06-03T17:49:29.226Z,1591206569.226 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-06-03T17:49:29.227Z,1591206569.227 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-06-03T17:49:29.232Z,1591206569.232 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-06-03T17:49:29.233Z,1591206569.233 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-06-03T17:49:29.238Z,1591206569.238 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-06-03T17:49:29.266Z,1591206569.266 [CTD_Seabird] Loaded 2020-06-03T17:49:29.267Z,1591206569.267 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-06-03T17:49:29.268Z,1591206569.268 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A9B4E0 2020-06-03T17:49:29.268Z,1591206569.268 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 908 2020-06-03T17:49:29.301Z,1591206569.301 [ESPComponent] Loaded 2020-06-03T17:49:29.301Z,1591206569.301 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2020-06-03T17:49:29.316Z,1591206569.316 [PAR_Licor] Loaded 2020-06-03T17:49:29.316Z,1591206569.316 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2020-06-03T17:49:29.323Z,1591206569.323 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-06-03T17:49:29.323Z,1591206569.323 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-06-03T17:49:29.327Z,1591206569.327 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-06-03T17:49:29.327Z,1591206569.327 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-06-03T17:49:29.332Z,1591206569.332 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-06-03T17:49:29.332Z,1591206569.332 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-06-03T17:49:29.336Z,1591206569.336 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-06-03T17:49:29.336Z,1591206569.336 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-06-03T17:49:29.340Z,1591206569.340 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-06-03T17:49:29.341Z,1591206569.341 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-06-03T17:49:29.345Z,1591206569.345 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-06-03T17:49:29.345Z,1591206569.345 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-06-03T17:49:29.349Z,1591206569.349 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-06-03T17:49:29.350Z,1591206569.350 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-06-03T17:49:29.354Z,1591206569.354 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.359Z,1591206569.359 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.359Z,1591206569.359 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.359Z,1591206569.359 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.363Z,1591206569.363 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.364Z,1591206569.364 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.368Z,1591206569.368 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.368Z,1591206569.368 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-06-03T17:49:29.372Z,1591206569.372 [WetLabsBB2FL] Loaded 2020-06-03T17:49:29.373Z,1591206569.373 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-06-03T17:49:29.374Z,1591206569.374 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40ACB4E0 2020-06-03T17:49:29.374Z,1591206569.374 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 909 2020-06-03T17:49:29.375Z,1591206569.375 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-06-03T17:49:29.376Z,1591206569.376 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-06-03T17:49:29.537Z,1591206569.537 [SBIT](DEBUG): Construct Startup Built In Test. 2020-06-03T17:49:29.549Z,1591206569.549 [SBIT] Loaded 2020-06-03T17:49:29.549Z,1591206569.549 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-06-03T17:49:29.550Z,1591206569.550 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-06-03T17:49:29.563Z,1591206569.563 [IBIT] Loaded 2020-06-03T17:49:29.563Z,1591206569.563 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-06-03T17:49:29.567Z,1591206569.567 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-06-03T17:49:29.709Z,1591206569.709 [CBIT] Loaded 2020-06-03T17:49:29.709Z,1591206569.709 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-06-03T17:49:29.710Z,1591206569.710 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-06-03T17:49:29.713Z,1591206569.713 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-06-03T17:49:29.714Z,1591206569.714 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-06-03T17:49:29.721Z,1591206569.721 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-06-03T17:49:29.722Z,1591206569.722 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B364E0 2020-06-03T17:49:29.723Z,1591206569.723 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 910 2020-06-03T17:49:29.727Z,1591206569.727 [Supervisor](INFO): Main Thread ID is 816 2020-06-03T17:49:29.728Z,1591206569.728 [Supervisor](DEBUG): Running supervisor. 2020-06-03T17:49:29.728Z,1591206569.728 [CommandLine ThreadHandler](INFO): Handler Thread ID is 911 2020-06-03T17:49:29.731Z,1591206569.731 [controlThread ThreadHandler](INFO): Handler Thread ID is 912 2020-06-03T17:49:29.731Z,1591206569.731 [controlThread](DEBUG): Initializing ControlThread 2020-06-03T17:49:29.732Z,1591206569.732 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-06-03T17:49:29.732Z,1591206569.732 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-06-03T17:49:29.732Z,1591206569.732 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-06-03T17:49:29.733Z,1591206569.733 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-06-03T17:49:29.733Z,1591206569.733 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-06-03T17:49:29.734Z,1591206569.734 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-06-03T17:49:29.734Z,1591206569.734 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-06-03T17:49:29.736Z,1591206569.736 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-06-03T17:49:29.737Z,1591206569.737 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-06-03T17:49:29.737Z,1591206569.737 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-06-03T17:49:29.738Z,1591206569.738 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-06-03T17:49:29.738Z,1591206569.738 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-06-03T17:49:29.746Z,1591206569.746 [SBIT](INFO): Initialize SBIT Component. 2020-06-03T17:49:29.746Z,1591206569.746 [SBIT](IMPORTANT): git: 2020-02-26-57-ge3d47c480 2020-06-03T17:49:29.747Z,1591206569.747 [SBIT](INFO): git hash: e3d47c48073008b6ccf34436fff8bd8e6f62e894 2020-06-03T17:49:29.747Z,1591206569.747 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-06-03T17:49:29.747Z,1591206569.747 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 2020-06-03T17:49:29.748Z,1591206569.748 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2020-06-03T17:49:29.749Z,1591206569.749 [IBIT](INFO): Initialize IBIT Component. 2020-06-03T17:49:29.750Z,1591206569.750 [CBIT](DEBUG): Initialize CBIT Component. 2020-06-03T17:49:29.751Z,1591206569.751 [logger ThreadHandler](INFO): Handler Thread ID is 913 2020-06-03T17:49:29.761Z,1591206569.761 [CBIT](DEBUG): Initialized mux pins. 2020-06-03T17:49:29.761Z,1591206569.761 [CBIT](DEBUG): Initializing the watchdog timer. 2020-06-03T17:49:29.769Z,1591206569.769 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 914 2020-06-03T17:49:29.770Z,1591206569.770 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-06-03T17:49:29.781Z,1591206569.781 [Onboard ThreadHandler](INFO): Handler Thread ID is 915 2020-06-03T17:49:29.785Z,1591206569.785 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-06-03T17:49:29.786Z,1591206569.786 [CBIT](DEBUG): Initializing heartbeat. 2020-06-03T17:49:29.799Z,1591206569.799 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 916 2020-06-03T17:49:29.817Z,1591206569.817 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 917 2020-06-03T17:49:29.818Z,1591206569.818 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-06-03T17:49:29.821Z,1591206569.821 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2020-06-03T17:49:29.822Z,1591206569.822 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 919 2020-06-03T17:49:29.823Z,1591206569.823 [WetLabsBB2FL](INFO): Powering down 2020-06-03T17:49:29.857Z,1591206569.857 [CBIT](DEBUG): Deactivating GF circuits. 2020-06-03T17:49:29.857Z,1591206569.857 [CBIT](DEBUG): Deactivating emergency mode. 2020-06-03T17:49:29.865Z,1591206569.865 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 920 2020-06-03T17:49:29.893Z,1591206569.893 [CBIT](DEBUG): Backplane powered. 2020-06-03T17:49:29.947Z,1591206569.947 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-06-03T17:49:30.055Z,1591206570.055 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-06-03T17:49:30.055Z,1591206570.055 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-06-03T17:49:30.056Z,1591206570.056 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-06-03T17:49:30.056Z,1591206570.056 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-06-03T17:49:30.056Z,1591206570.056 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-06-03T17:49:30.056Z,1591206570.056 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-06-03T17:49:30.056Z,1591206570.056 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-06-03T17:49:30.056Z,1591206570.056 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-06-03T17:49:30.057Z,1591206570.057 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-06-03T17:49:30.057Z,1591206570.057 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-06-03T17:49:30.057Z,1591206570.057 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-06-03T17:49:30.058Z,1591206570.058 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-06-03T17:49:30.058Z,1591206570.058 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-06-03T17:49:30.058Z,1591206570.058 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-06-03T17:49:30.058Z,1591206570.058 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-06-03T17:49:30.058Z,1591206570.058 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-06-03T17:49:30.159Z,1591206570.159 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-06-03T17:49:30.177Z,1591206570.177 [MissionManager](DEBUG): 2020-06-03T17:49:30.178Z,1591206570.178 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-06-03T17:49:30.205Z,1591206570.205 [Radio_Surface](INFO): Powering up 2020-06-03T17:49:30.256Z,1591206570.256 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-06-03T17:49:30.281Z,1591206570.281 [Default:A.Wait](DEBUG): Construct Wait. 2020-06-03T17:49:30.282Z,1591206570.282 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-06-03T17:49:30.309Z,1591206570.309 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-06-03T17:49:30.312Z,1591206570.312 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-06-03T17:49:30.334Z,1591206570.334 [Default:E.Execute](DEBUG): Construct Execute. 2020-06-03T17:49:30.362Z,1591206570.362 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2020-06-03T17:49:30.366Z,1591206570.366 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,DAT,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2020-06-03T17:49:30.385Z,1591206570.385 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-06-03T17:49:30.471Z,1591206570.471 [Depth_Keller](ERROR): Pressure reading out of range: 1829.799438 decibar 2020-06-03T17:49:30.484Z,1591206570.484 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-03T17:49:30.484Z,1591206570.484 [DAT](INFO): Powering up 2020-06-03T17:49:30.484Z,1591206570.484 [DAT](DEBUG): Initializing DAT. 2020-06-03T17:49:30.530Z,1591206570.530 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-03T17:49:30.553Z,1591206570.553 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-06-03T17:49:30.623Z,1591206570.623 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-06-03T17:49:30.633Z,1591206570.633 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-06-03T17:49:30.634Z,1591206570.634 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-06-03T17:49:30.645Z,1591206570.645 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-06-03T17:49:30.646Z,1591206570.646 [MassServo](DEBUG): Initializing EZServoServo. 2020-06-03T17:49:30.657Z,1591206570.657 [MassServo](DEBUG): Initializing MassServo. 2020-06-03T17:49:30.658Z,1591206570.658 [RudderServo](DEBUG): Initializing EZServoServo. 2020-06-03T17:49:30.665Z,1591206570.665 [RudderServo](DEBUG): Initializing RudderServo. 2020-06-03T17:49:30.666Z,1591206570.666 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-06-03T17:49:30.673Z,1591206570.673 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-06-03T17:49:30.914Z,1591206570.914 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2020-06-03T17:49:30.914Z,1591206570.914 [DropWeight] Hardware Fault, FailCount= 1 2020-06-03T17:49:30.914Z,1591206570.914 [DropWeight](ERROR): Hardware Fault 2020-06-03T17:49:30.988Z,1591206570.988 [CommandLine](FAULT): Scheduling is paused 2020-06-03T17:49:30.989Z,1591206570.989 [CBIT](INFO): Critical error at 20200603T174930 2020-06-03T17:49:30.989Z,1591206570.989 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-06-03T17:49:30.991Z,1591206570.991 [CBIT](ERROR): Hardware Fault in component: DropWeight 2020-06-03T17:49:30.992Z,1591206570.992 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2020-06-03T17:49:31.509Z,1591206571.509 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-06-03T17:49:31.509Z,1591206571.509 [RudderServo](FAULT): Rudder failed to initialize 2020-06-03T17:49:31.509Z,1591206571.509 [RudderServo] Communications Fault, FailCount= 1 2020-06-03T17:49:31.509Z,1591206571.509 [RudderServo](ERROR): Communications Fault 2020-06-03T17:49:31.702Z,1591206571.702 [CBIT](INFO): Critical error at 20200603T174930 2020-06-03T17:49:31.705Z,1591206571.705 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-06-03T17:49:31.866Z,1591206571.866 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-06-03T17:49:31.866Z,1591206571.866 [RudderServo](INFO): Powering down 2020-06-03T17:49:32.536Z,1591206572.536 [RudderServo](DEBUG): Initializing EZServoServo. 2020-06-03T17:49:32.654Z,1591206572.654 [RudderServo](DEBUG): Initializing RudderServo. 2020-06-03T17:49:32.658Z,1591206572.658 [CBIT](INFO): Clearing failed state for component RudderServo 2020-06-03T17:49:32.658Z,1591206572.658 [RudderServo] No Fault, FailCount= 1 2020-06-03T17:49:36.849Z,1591206576.849 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2020-06-03T17:49:42.222Z,1591206582.222 [DAT](DEBUG): 2020-06-03T17:49:42.223Z,1591206582.223 [DAT](DEBUG): Teledyne Benthos DAT-900 Series 2020-06-03T17:49:43.435Z,1591206583.435 [DAT](DEBUG): MF Frequency Band 2020-06-03T17:49:43.437Z,1591206583.437 [DAT](DEBUG): Directional Acoustic Transponder version 8.14.0 2020-06-03T17:49:43.839Z,1591206583.839 [DAT](DEBUG): Jun 3 2020 17:49:20 2020-06-03T17:49:44.647Z,1591206584.647 [DAT](DEBUG): Features enabled [Bearing] 2020-06-03T17:49:44.648Z,1591206584.648 [DAT](DEBUG): CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2020-06-03T17:49:44.648Z,1591206584.648 [DAT](INFO): commRate: 800 2020-06-03T17:49:45.052Z,1591206585.052 [DAT](INFO): entering command mode 2020-06-03T17:49:45.531Z,1591206585.531 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-03T17:49:45.862Z,1591206585.862 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-03T17:49:46.277Z,1591206586.277 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-03T17:49:46.277Z,1591206586.277 [DAT](INFO): command mode acknowledged 2020-06-03T17:49:46.277Z,1591206586.277 [DAT](INFO): setting verbose to 3 2020-06-03T17:49:46.675Z,1591206586.675 [DAT](DEBUG): checking for verbose setting acknowledgment 2020-06-03T17:49:46.676Z,1591206586.676 [DAT](INFO): set verbose to 3 2020-06-03T17:49:47.079Z,1591206587.079 [DAT](INFO): setting transmit power to 8 2020-06-03T17:49:47.485Z,1591206587.485 [DAT](DEBUG): checking for transmit power setting acknowledgment 2020-06-03T17:49:47.879Z,1591206587.879 [DAT](DEBUG): checking for transmit power setting acknowledgment 2020-06-03T17:49:47.880Z,1591206587.880 [DAT](INFO): set transmit power to 8 2020-06-03T17:49:48.292Z,1591206588.292 [DAT](INFO): setting local address to 8 2020-06-03T17:49:48.687Z,1591206588.687 [DAT](DEBUG): checking for local address setting acknowledgment 2020-06-03T17:49:49.091Z,1591206589.091 [DAT](DEBUG): checking for local address setting acknowledgment 2020-06-03T17:49:49.091Z,1591206589.091 [DAT](INFO): set local address to 8 2020-06-03T17:49:56.770Z,1591206596.770 [NAL9602](INFO): Powering up NAL9602 2020-06-03T17:50:07.675Z,1591206607.675 [NAL9602](INFO): NAL9602 initialized 2020-06-03T17:50:29.504Z,1591206629.504 [SBIT](IMPORTANT): Beginning Startup BIT 2020-06-03T17:50:29.524Z,1591206629.524 [CBIT](IMPORTANT): Beginning ground fault scan 2020-06-03T17:50:40.593Z,1591206640.593 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.017938 CHAN A1 (24V): 0.003442 CHAN A2 (12V): -0.005688 CHAN A3 (5V): -0.003758 CHAN B0 (3.3V): -0.001867 CHAN B1 (3.15aV): -0.001534 CHAN B2 (3.15bV): -0.001352 CHAN B3 (GND): -0.001522 OPEN: -0.005112 Full Scale Calc: 4.765 mA, -1.589 mA 2020-06-03T17:51:22.772Z,1591206682.772 [SBIT](IMPORTANT): SBIT PASSED 2020-06-03T17:51:22.772Z,1591206682.772 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-06-03T17:51:22.774Z,1591206682.774 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool; 2020-06-03T17:51:22.774Z,1591206682.774 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool; 2020-06-03T17:51:22.774Z,1591206682.774 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=242.907926 cubic_centimeter; 2020-06-03T17:51:22.774Z,1591206682.774 [SBIT](IMPORTANT): VerticalControl.massDefault=9.890285 millimeter; 2020-06-03T17:51:23.168Z,1591206683.168 [MissionManager](IMPORTANT): Started mission Startup 2020-06-03T17:51:23.168Z,1591206683.168 [Startup] Running Loop=1 2020-06-03T17:51:23.168Z,1591206683.168 [Startup](DEBUG): Aggregate::initialize Startup 2020-06-03T17:51:23.169Z,1591206683.169 [Startup:A.GoToSurface] Running Loop=1 2020-06-03T17:51:23.169Z,1591206683.169 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-06-03T17:51:23.169Z,1591206683.169 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-06-03T17:51:23.170Z,1591206683.170 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-06-03T17:51:23.170Z,1591206683.170 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-06-03T17:51:23.171Z,1591206683.171 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-06-03T17:51:23.171Z,1591206683.171 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-06-03T17:51:23.172Z,1591206683.172 [Startup:StartupSatComms] Running Loop=1 2020-06-03T17:51:23.172Z,1591206683.172 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-06-03T17:51:23.173Z,1591206683.173 [Startup:StartupSatComms:A] Running Loop=1 2020-06-03T17:51:23.582Z,1591206683.582 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-06-03T17:51:55.543Z,1591206715.543 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004897 2020-06-03T17:52:23.390Z,1591206743.390 [Startup:StartupSatComms:A](INFO): Timed out from 2020-06-03T17:51:23.2Z 2020-06-03T17:52:23.390Z,1591206743.390 [Startup:StartupSatComms:A] Stopped 2020-06-03T17:52:23.390Z,1591206743.390 [Startup:StartupSatComms:B] Running Loop=1 2020-06-03T17:52:23.790Z,1591206743.790 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-06-03T17:52:29.850Z,1591206749.850 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-06-03T17:52:29.850Z,1591206749.850 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-03T17:52:29.888Z,1591206749.888 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-03T17:52:30.274Z,1591206750.274 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-03T17:52:30.274Z,1591206750.274 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-06-03T17:52:32.822Z,1591206752.822 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20200602T222117/Courier0337.lzma 2020-06-03T17:52:33.823Z,1591206753.823 [DataOverHttps](INFO): Moved sent file to Logs/20200602T222117/Courier0337.lzma.bak 2020-06-03T17:52:33.823Z,1591206753.823 [DataOverHttps](INFO): SBD MOMSN=12362754 2020-06-03T17:52:48.433Z,1591206768.433 [DAT](INFO): unknown deviceResponse_: Lowpower 2020-06-03T17:52:50.937Z,1591206770.937 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20200603T174916/Courier0000.lzma 2020-06-03T17:52:51.939Z,1591206771.939 [DataOverHttps](INFO): Moved sent file to Logs/20200603T174916/Courier0000.lzma.bak 2020-06-03T17:52:51.939Z,1591206771.939 [DataOverHttps](INFO): SBD MOMSN=12362758 2020-06-03T17:53:10.279Z,1591206790.279 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20200602T222117/Express0338.lzma 2020-06-03T17:53:10.979Z,1591206790.979 [DataOverHttps](INFO): Moved sent file to Logs/20200602T222117/Express0338.lzma.bak 2020-06-03T17:53:10.979Z,1591206790.979 [DataOverHttps](INFO): SBD MOMSN=12362763 2020-06-03T17:53:23.571Z,1591206803.571 [Startup:StartupSatComms:B](INFO): Timed out from 2020-06-03T17:52:23.4Z 2020-06-03T17:53:23.571Z,1591206803.571 [Startup:StartupSatComms:B] Stopped 2020-06-03T17:53:23.571Z,1591206803.571 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-06-03T17:53:23.571Z,1591206803.571 [Startup:StartupSatComms] Stopped 2020-06-03T17:53:23.572Z,1591206803.572 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-06-03T17:53:23.572Z,1591206803.572 [Startup](INFO): Completed Startup 2020-06-03T17:53:23.572Z,1591206803.572 [MissionManager](INFO): Startup is completed. 2020-06-03T17:53:23.573Z,1591206803.573 [MissionManager](INFO): Uninitializing Mission Startup 2020-06-03T17:53:23.573Z,1591206803.573 [Startup] Stopped 2020-06-03T17:53:23.573Z,1591206803.573 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-06-03T17:53:23.573Z,1591206803.573 [Startup:A.GoToSurface] Stopped 2020-06-03T17:53:23.573Z,1591206803.573 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-06-03T17:53:23.986Z,1591206803.986 [MissionManager](IMPORTANT): Started mission Default 2020-06-03T17:53:23.987Z,1591206803.987 [Default] Running Loop=1 2020-06-03T17:53:23.987Z,1591206803.987 [Default](DEBUG): Aggregate::initialize Default 2020-06-03T17:53:23.987Z,1591206803.987 [Default:B.GoToSurface] Running Loop=1 2020-06-03T17:53:23.987Z,1591206803.987 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-06-03T17:53:23.987Z,1591206803.987 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-06-03T17:53:23.988Z,1591206803.988 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-06-03T17:53:23.988Z,1591206803.988 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-06-03T17:53:23.988Z,1591206803.988 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-06-03T17:53:23.988Z,1591206803.988 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-06-03T17:53:23.989Z,1591206803.989 [Default:A.Wait] Running Loop=1 2020-06-03T17:53:23.989Z,1591206803.989 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-06-03T17:53:30.102Z,1591206810.102 [DataOverHttps](INFO): Sending 861 bytes from file Logs/20200603T174916/Express0001.lzma 2020-06-03T17:53:31.102Z,1591206811.102 [DataOverHttps](INFO): Moved sent file to Logs/20200603T174916/Express0001.lzma.bak 2020-06-03T17:53:31.103Z,1591206811.103 [DataOverHttps](INFO): SBD MOMSN=12362767 2020-06-03T17:53:37.325Z,1591206817.325 [Default:A.Wait](INFO): Done Waiting. 2020-06-03T17:53:37.325Z,1591206817.325 [Default:A.Wait] Stopped 2020-06-03T17:53:37.325Z,1591206817.325 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-06-03T17:53:37.722Z,1591206817.722 [Default:CheckIn] Running Loop=1 2020-06-03T17:53:37.722Z,1591206817.722 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-03T17:53:37.722Z,1591206817.722 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-03T17:53:38.119Z,1591206818.119 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-06-03T17:54:07.622Z,1591206847.622 [DVL_micro](ERROR): Failed to parse: :SA,-01.12,-06.74,039.6 2020-06-03T17:55:10.627Z,1591206910.627 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-06-03T17:55:30.830Z,1591206930.830 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-06-03T17:55:30.830Z,1591206930.830 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-03T17:55:30.840Z,1591206930.840 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-03T17:55:31.244Z,1591206931.244 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-03T17:55:31.244Z,1591206931.244 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-06-03T17:58:02.797Z,1591207082.797 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-06-03T17:58:31.858Z,1591207111.858 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-06-03T17:58:31.858Z,1591207111.858 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-03T17:58:31.868Z,1591207111.868 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-03T17:58:32.269Z,1591207112.269 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-03T17:58:32.269Z,1591207112.269 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-06-03T17:58:37.907Z,1591207117.907 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-03T17:53:37.7Z 2020-06-03T17:58:37.907Z,1591207117.907 [Default:CheckIn:Read_GPS] Stopped 2020-06-03T17:58:37.907Z,1591207117.907 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-03T17:58:38.294Z,1591207118.294 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-06-03T17:58:45.348Z,1591207125.348 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200603T174916/Courier0004.lzma 2020-06-03T17:58:46.350Z,1591207126.350 [DataOverHttps](INFO): Moved sent file to Logs/20200603T174916/Courier0004.lzma.bak 2020-06-03T17:58:46.351Z,1591207126.351 [DataOverHttps](INFO): SBD MOMSN=12362795 2020-06-03T17:59:02.933Z,1591207142.933 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-03T17:59:02.933Z,1591207142.933 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,14 2020-06-03T17:59:05.322Z,1591207145.322 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20200603T174916/Express0005.lzma 2020-06-03T17:59:06.323Z,1591207146.323 [DataOverHttps](INFO): Moved sent file to Logs/20200603T174916/Express0005.lzma.bak 2020-06-03T17:59:06.323Z,1591207146.323 [DataOverHttps](INFO): SBD MOMSN=12362797 2020-06-03T17:59:10.651Z,1591207150.651 [Default:CheckIn:Read_Iridium] Stopped 2020-06-03T17:59:10.651Z,1591207150.651 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-03T17:59:10.651Z,1591207150.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-03T18:00:09.991Z,1591207209.991 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-03T18:00:09.991Z,1591207209.991 [NAL9602] Data Fault, FailCount= 1 2020-06-03T18:00:09.991Z,1591207209.991 [NAL9602](ERROR): Data Fault 2020-06-03T18:00:10.037Z,1591207210.037 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-03T18:00:10.386Z,1591207210.386 [NAL9602](INFO): Powering down 2020-06-03T18:00:11.236Z,1591207211.236 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-03T18:00:11.236Z,1591207211.236 [NAL9602] No Fault, FailCount= 1 2020-06-03T18:00:40.690Z,1591207240.690 [NAL9602](INFO): Powering up NAL9602 2020-06-03T18:00:51.603Z,1591207251.603 [NAL9602](INFO): NAL9602 initialized 2020-06-03T18:01:32.823Z,1591207292.823 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-06-03T18:01:32.823Z,1591207292.823 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-03T18:01:32.848Z,1591207292.848 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-03T18:01:33.257Z,1591207293.257 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-03T18:01:33.257Z,1591207293.257 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-06-03T18:04:11.201Z,1591207451.201 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-03T18:04:11.201Z,1591207451.201 [Default:CheckIn:C.Wait] Stopped 2020-06-03T18:04:11.201Z,1591207451.201 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-03T18:04:11.201Z,1591207451.201 [Default:CheckIn:D] Running Loop=1 2020-06-03T18:04:11.614Z,1591207451.614 [Default:CheckIn:D] Stopped 2020-06-03T18:04:11.614Z,1591207451.614 [Default:CheckIn:E] Running Loop=1 2020-06-03T18:04:12.011Z,1591207452.011 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.793788 min 2020-06-03T18:04:12.011Z,1591207452.011 [Default:CheckIn:E] Stopped 2020-06-03T18:04:12.011Z,1591207452.011 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-03T18:04:12.011Z,1591207452.011 [Default:CheckIn] Stopped 2020-06-03T18:04:12.012Z,1591207452.012 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-03T18:04:12.012Z,1591207452.012 [Default:CheckIn](INFO): Running loop #2 2020-06-03T18:04:12.012Z,1591207452.012 [Default:CheckIn] Running Loop=2 2020-06-03T18:04:12.012Z,1591207452.012 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-03T18:04:12.012Z,1591207452.012 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-03T18:04:31.014Z,1591207471.014 [CBIT](INFO): Clearing failed state for component DropWeight 2020-06-03T18:04:31.014Z,1591207471.014 [DropWeight] No Fault, FailCount= 1 2020-06-03T18:04:33.842Z,1591207473.842 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-06-03T18:04:33.842Z,1591207473.842 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-03T18:04:33.852Z,1591207473.852 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-03T18:04:34.219Z,1591207474.219 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-03T18:04:34.219Z,1591207474.219 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-06-03T18:07:34.814Z,1591207654.814 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-06-03T18:07:34.814Z,1591207654.814 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-03T18:07:34.840Z,1591207654.840 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-03T18:07:35.219Z,1591207655.219 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-03T18:07:35.219Z,1591207655.219 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-06-03T18:09:12.171Z,1591207752.171 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-03T18:04:12.0Z 2020-06-03T18:09:12.171Z,1591207752.171 [Default:CheckIn:Read_GPS] Stopped 2020-06-03T18:09:12.171Z,1591207752.171 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-03T18:09:21.032Z,1591207761.032 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200603T174916/Courier0007.lzma 2020-06-03T18:09:22.034Z,1591207762.034 [DataOverHttps](INFO): Moved sent file to Logs/20200603T174916/Courier0007.lzma.bak 2020-06-03T18:09:22.035Z,1591207762.035 [DataOverHttps](INFO): SBD MOMSN=12362813 2020-06-03T18:09:41.021Z,1591207781.021 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20200603T174916/Express0008.lzma 2020-06-03T18:09:42.023Z,1591207782.023 [DataOverHttps](INFO): Moved sent file to Logs/20200603T174916/Express0008.lzma.bak 2020-06-03T18:09:42.023Z,1591207782.023 [DataOverHttps](INFO): SBD MOMSN=12362815 2020-06-03T18:09:46.522Z,1591207786.522 [Default:CheckIn:Read_Iridium] Stopped 2020-06-03T18:09:46.522Z,1591207786.522 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-03T18:09:46.522Z,1591207786.522 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-03T18:10:35.802Z,1591207835.802 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-06-03T18:10:35.802Z,1591207835.802 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-03T18:10:35.840Z,1591207835.840 [CBIT](ERROR): Software Fault in component: