2019-12-06T19:46:02.229Z,1575661562.229 [Supervisor](DEBUG): Initializing supervisor. 2019-12-06T19:46:02.232Z,1575661562.232 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-12-06T19:46:02.233Z,1575661562.233 [SyncHandler](INFO): Protected caller Thread ID is 334 2019-12-06T19:46:02.234Z,1575661562.234 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-12-06T19:46:02.235Z,1575661562.235 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-12-06T19:46:02.235Z,1575661562.235 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 335 2019-12-06T19:46:02.239Z,1575661562.239 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-12-06T19:46:02.251Z,1575661562.251 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-12-06T19:46:02.252Z,1575661562.252 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-12-06T19:46:02.252Z,1575661562.252 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 336 2019-12-06T19:46:02.253Z,1575661562.253 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-12-06T19:46:02.254Z,1575661562.254 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-12-06T19:46:02.254Z,1575661562.254 [logger ThreadHandler](INFO): Protected caller Thread ID is 337 2019-12-06T19:46:02.256Z,1575661562.256 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-12-06T19:46:02.257Z,1575661562.257 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-12-06T19:46:02.258Z,1575661562.258 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-12-06T19:46:02.354Z,1575661562.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-12-06T19:46:02.354Z,1575661562.354 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-12-06T19:46:02.935Z,1575661562.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-12-06T19:46:02.936Z,1575661562.936 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-12-06T19:46:03.034Z,1575661563.034 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-12-06T19:46:03.035Z,1575661563.035 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-12-06T19:46:03.135Z,1575661563.135 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-12-06T19:46:03.136Z,1575661563.136 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-12-06T19:46:03.216Z,1575661563.216 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-12-06T19:46:03.352Z,1575661563.352 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-12-06T19:46:03.352Z,1575661563.352 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-12-06T19:46:03.634Z,1575661563.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-12-06T19:46:03.635Z,1575661563.635 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-12-06T19:46:04.073Z,1575661564.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-12-06T19:46:04.074Z,1575661564.074 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-12-06T19:46:04.219Z,1575661564.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-12-06T19:46:04.219Z,1575661564.219 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-12-06T19:46:04.403Z,1575661564.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-12-06T19:46:04.403Z,1575661564.403 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-12-06T19:46:04.850Z,1575661564.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-12-06T19:46:04.851Z,1575661564.851 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-12-06T19:46:05.057Z,1575661565.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-12-06T19:46:05.058Z,1575661565.057 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-12-06T19:46:05.251Z,1575661565.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-12-06T19:46:05.252Z,1575661565.252 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-12-06T19:46:05.646Z,1575661565.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-12-06T19:46:05.646Z,1575661565.646 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-12-06T19:46:05.960Z,1575661565.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-12-06T19:46:05.962Z,1575661565.962 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2019-12-06T19:46:05.963Z,1575661565.963 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2019-12-06T19:46:06.047Z,1575661566.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2019-12-06T19:46:06.210Z,1575661566.210 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2019-12-06T19:46:06.448Z,1575661566.448 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2019-12-06T19:46:06.704Z,1575661566.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2019-12-06T19:46:06.810Z,1575661566.810 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2019-12-06T19:46:07.237Z,1575661567.237 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2019-12-06T19:46:07.463Z,1575661567.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-12-06T19:46:07.464Z,1575661567.464 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2019-12-06T19:46:07.557Z,1575661567.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2019-12-06T19:46:07.655Z,1575661567.655 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2019-12-06T19:46:07.790Z,1575661567.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2019-12-06T19:46:07.889Z,1575661567.889 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2019-12-06T19:46:07.890Z,1575661567.890 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-12-06T19:46:07.900Z,1575661567.900 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-12-06T19:46:07.949Z,1575661567.949 [VerticalControl](DEBUG): Construct VerticalControl. 2019-12-06T19:46:08.060Z,1575661568.060 [VerticalControl] Loaded 2019-12-06T19:46:08.061Z,1575661568.061 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-12-06T19:46:08.062Z,1575661568.062 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-12-06T19:46:08.142Z,1575661568.142 [HorizontalControl] Loaded 2019-12-06T19:46:08.142Z,1575661568.142 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-12-06T19:46:08.143Z,1575661568.143 [SpeedControl](DEBUG): Construct SpeedControl. 2019-12-06T19:46:08.148Z,1575661568.148 [SpeedControl] Loaded 2019-12-06T19:46:08.149Z,1575661568.149 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-12-06T19:46:08.149Z,1575661568.149 [LoopControl](DEBUG): Construct LoopControl. 2019-12-06T19:46:08.150Z,1575661568.150 [LoopControl] Loaded 2019-12-06T19:46:08.150Z,1575661568.150 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-12-06T19:46:08.151Z,1575661568.151 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-12-06T19:46:08.151Z,1575661568.151 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-12-06T19:46:08.192Z,1575661568.192 [DepthRateCalculator] Loaded 2019-12-06T19:46:08.193Z,1575661568.193 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-12-06T19:46:08.198Z,1575661568.198 [PitchRateCalculator] Loaded 2019-12-06T19:46:08.198Z,1575661568.198 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-12-06T19:46:08.213Z,1575661568.213 [SpeedCalculator] Loaded 2019-12-06T19:46:08.213Z,1575661568.213 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-12-06T19:46:08.234Z,1575661568.234 [TempGradientCalculator] Loaded 2019-12-06T19:46:08.235Z,1575661568.235 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-12-06T19:46:08.240Z,1575661568.240 [YawRateCalculator] Loaded 2019-12-06T19:46:08.240Z,1575661568.240 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-12-06T19:46:08.269Z,1575661568.269 [ElevatorOffsetCalculator] Loaded 2019-12-06T19:46:08.269Z,1575661568.269 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-12-06T19:46:08.269Z,1575661568.269 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-12-06T19:46:08.270Z,1575661568.270 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-12-06T19:46:08.304Z,1575661568.304 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-12-06T19:46:08.305Z,1575661568.305 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-12-06T19:46:08.391Z,1575661568.391 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-12-06T19:46:08.392Z,1575661568.392 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-12-06T19:46:08.707Z,1575661568.707 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-12-06T19:46:08.707Z,1575661568.707 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-12-06T19:46:08.807Z,1575661568.807 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-12-06T19:46:08.808Z,1575661568.808 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-12-06T19:46:09.127Z,1575661569.127 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-12-06T19:46:09.132Z,1575661569.132 [AHRS_M2](INFO): created writer for : platform_orientation 2019-12-06T19:46:09.135Z,1575661569.135 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-12-06T19:46:09.140Z,1575661569.140 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-12-06T19:46:09.140Z,1575661569.140 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-12-06T19:46:09.145Z,1575661569.145 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-12-06T19:46:09.146Z,1575661569.146 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-12-06T19:46:09.151Z,1575661569.151 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-12-06T19:46:09.222Z,1575661569.222 [AHRS_M2] Loaded 2019-12-06T19:46:09.222Z,1575661569.222 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-12-06T19:46:09.302Z,1575661569.302 [DataOverHttps] Loaded 2019-12-06T19:46:09.303Z,1575661569.303 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-12-06T19:46:09.304Z,1575661569.304 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408E34E0 2019-12-06T19:46:09.304Z,1575661569.304 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 419 2019-12-06T19:46:09.318Z,1575661569.318 [Depth_Keller] Loaded 2019-12-06T19:46:09.318Z,1575661569.318 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-12-06T19:46:09.415Z,1575661569.415 [NAL9602] Loaded 2019-12-06T19:46:09.416Z,1575661569.416 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-12-06T19:46:09.453Z,1575661569.453 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now 2019-12-06T19:46:09.454Z,1575661569.454 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now 2019-12-06T19:46:09.454Z,1575661569.454 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now 2019-12-06T19:46:09.455Z,1575661569.455 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full 2019-12-06T19:46:09.455Z,1575661569.455 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now 2019-12-06T19:46:09.456Z,1575661569.456 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now 2019-12-06T19:46:09.456Z,1575661569.456 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now 2019-12-06T19:46:09.457Z,1575661569.457 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full 2019-12-06T19:46:09.457Z,1575661569.457 [Onboard] Loaded 2019-12-06T19:46:09.457Z,1575661569.457 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-12-06T19:46:09.460Z,1575661569.460 [Radio_Surface] Loaded 2019-12-06T19:46:09.460Z,1575661569.460 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-12-06T19:46:09.462Z,1575661569.462 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409134E0 2019-12-06T19:46:09.462Z,1575661569.462 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 420 2019-12-06T19:46:09.594Z,1575661569.594 [DAT] Loaded 2019-12-06T19:46:09.594Z,1575661569.594 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-12-06T19:46:11.094Z,1575661571.094 [BPC1] Loaded 2019-12-06T19:46:11.094Z,1575661571.094 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-12-06T19:46:11.095Z,1575661571.095 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-12-06T19:46:11.095Z,1575661571.095 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-12-06T19:46:11.197Z,1575661571.197 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-12-06T19:46:11.197Z,1575661571.197 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-12-06T19:46:11.218Z,1575661571.218 [NavChart] Loaded 2019-12-06T19:46:11.219Z,1575661571.219 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-12-06T19:46:11.222Z,1575661571.222 [UniversalFixResidualReporter] Loaded 2019-12-06T19:46:11.223Z,1575661571.223 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-12-06T19:46:11.223Z,1575661571.223 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-12-06T19:46:11.224Z,1575661571.224 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-12-06T19:46:11.490Z,1575661571.490 [SBIT](DEBUG): Construct Startup Built In Test. 2019-12-06T19:46:11.501Z,1575661571.501 [SBIT] Loaded 2019-12-06T19:46:11.501Z,1575661571.501 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-12-06T19:46:11.502Z,1575661571.502 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-12-06T19:46:11.514Z,1575661571.514 [IBIT] Loaded 2019-12-06T19:46:11.514Z,1575661571.514 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-12-06T19:46:11.517Z,1575661571.517 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-12-06T19:46:11.652Z,1575661571.652 [CBIT] Loaded 2019-12-06T19:46:11.652Z,1575661571.652 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-12-06T19:46:11.652Z,1575661571.652 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-12-06T19:46:11.653Z,1575661571.653 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-12-06T19:46:11.757Z,1575661571.757 [BuoyancyServo] Loaded 2019-12-06T19:46:11.757Z,1575661571.757 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-12-06T19:46:11.768Z,1575661571.768 [ElevatorServo] Loaded 2019-12-06T19:46:11.769Z,1575661571.769 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-12-06T19:46:11.780Z,1575661571.780 [MassServo] Loaded 2019-12-06T19:46:11.780Z,1575661571.780 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-12-06T19:46:11.791Z,1575661571.791 [RudderServo] Loaded 2019-12-06T19:46:11.791Z,1575661571.791 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-12-06T19:46:11.802Z,1575661571.802 [ThrusterServo] Loaded 2019-12-06T19:46:11.802Z,1575661571.802 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-12-06T19:46:11.802Z,1575661571.802 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-12-06T19:46:11.803Z,1575661571.803 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-12-06T19:46:11.818Z,1575661571.818 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-12-06T19:46:11.818Z,1575661571.818 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-12-06T19:46:12.039Z,1575661572.039 [BackSeatDriver] Loaded 2019-12-06T19:46:12.039Z,1575661572.039 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread. 2019-12-06T19:46:12.040Z,1575661572.040 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40A994E0 2019-12-06T19:46:12.041Z,1575661572.041 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 421 2019-12-06T19:46:12.050Z,1575661572.050 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-12-06T19:46:12.055Z,1575661572.055 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-12-06T19:46:12.055Z,1575661572.055 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-12-06T19:46:12.060Z,1575661572.060 [CTD_Seabird](INFO): created writer for : depth 2019-12-06T19:46:12.061Z,1575661572.061 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-12-06T19:46:12.066Z,1575661572.066 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-12-06T19:46:12.066Z,1575661572.066 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-12-06T19:46:12.072Z,1575661572.072 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-12-06T19:46:12.072Z,1575661572.072 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-12-06T19:46:12.077Z,1575661572.077 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-12-06T19:46:12.078Z,1575661572.078 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-12-06T19:46:12.083Z,1575661572.083 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-12-06T19:46:12.084Z,1575661572.084 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-12-06T19:46:12.089Z,1575661572.089 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-12-06T19:46:12.116Z,1575661572.116 [CTD_Seabird] Loaded 2019-12-06T19:46:12.116Z,1575661572.116 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-12-06T19:46:12.117Z,1575661572.117 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AC94E0 2019-12-06T19:46:12.117Z,1575661572.117 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 422 2019-12-06T19:46:12.148Z,1575661572.148 [ESPComponent] Loaded 2019-12-06T19:46:12.148Z,1575661572.148 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-12-06T19:46:12.154Z,1575661572.154 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2019-12-06T19:46:12.154Z,1575661572.154 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2019-12-06T19:46:12.159Z,1575661572.159 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2019-12-06T19:46:12.159Z,1575661572.159 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2019-12-06T19:46:12.163Z,1575661572.163 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2019-12-06T19:46:12.163Z,1575661572.163 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2019-12-06T19:46:12.167Z,1575661572.167 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2019-12-06T19:46:12.168Z,1575661572.168 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2019-12-06T19:46:12.172Z,1575661572.172 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2019-12-06T19:46:12.172Z,1575661572.172 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2019-12-06T19:46:12.177Z,1575661572.177 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2019-12-06T19:46:12.177Z,1575661572.177 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2019-12-06T19:46:12.181Z,1575661572.181 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2019-12-06T19:46:12.181Z,1575661572.181 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2019-12-06T19:46:12.186Z,1575661572.186 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.190Z,1575661572.190 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.191Z,1575661572.191 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.191Z,1575661572.191 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.195Z,1575661572.195 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.196Z,1575661572.196 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.200Z,1575661572.200 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.200Z,1575661572.200 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-12-06T19:46:12.204Z,1575661572.204 [WetLabsBB2FL] Loaded 2019-12-06T19:46:12.205Z,1575661572.205 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-12-06T19:46:12.206Z,1575661572.206 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AF94E0 2019-12-06T19:46:12.206Z,1575661572.206 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 423 2019-12-06T19:46:12.207Z,1575661572.207 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-12-06T19:46:12.210Z,1575661572.210 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-12-06T19:46:12.211Z,1575661572.211 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-12-06T19:46:12.218Z,1575661572.218 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-12-06T19:46:12.219Z,1575661572.219 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B294E0 2019-12-06T19:46:12.219Z,1575661572.219 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 424 2019-12-06T19:46:12.224Z,1575661572.224 [Supervisor](INFO): Main Thread ID is 9855 2019-12-06T19:46:12.224Z,1575661572.224 [Supervisor](DEBUG): Running supervisor. 2019-12-06T19:46:12.225Z,1575661572.225 [CommandLine ThreadHandler](INFO): Handler Thread ID is 425 2019-12-06T19:46:12.227Z,1575661572.227 [controlThread ThreadHandler](INFO): Handler Thread ID is 426 2019-12-06T19:46:12.228Z,1575661572.228 [controlThread](DEBUG): Initializing ControlThread 2019-12-06T19:46:12.229Z,1575661572.229 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-12-06T19:46:12.230Z,1575661572.230 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-12-06T19:46:12.231Z,1575661572.231 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-12-06T19:46:12.231Z,1575661572.231 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-12-06T19:46:12.232Z,1575661572.232 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-12-06T19:46:12.232Z,1575661572.232 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-12-06T19:46:12.232Z,1575661572.232 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-12-06T19:46:12.233Z,1575661572.233 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-12-06T19:46:12.233Z,1575661572.233 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-12-06T19:46:12.233Z,1575661572.233 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-12-06T19:46:12.238Z,1575661572.238 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-12-06T19:46:12.239Z,1575661572.239 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-12-06T19:46:12.239Z,1575661572.239 [SBIT](INFO): Initialize SBIT Component. 2019-12-06T19:46:12.240Z,1575661572.240 [SBIT](IMPORTANT): git: 2019-12-03-30-g2a4987e 2019-12-06T19:46:12.240Z,1575661572.240 [SBIT](INFO): git hash: 2a4987e96c8b669b87467a147f24522d25eb9733 2019-12-06T19:46:12.240Z,1575661572.240 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-12-06T19:46:12.240Z,1575661572.240 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-12-06T19:46:12.242Z,1575661572.242 [SBIT](INFO): Beginning SBIT in 39.000000 seconds. 2019-12-06T19:46:12.242Z,1575661572.242 [IBIT](INFO): Initialize IBIT Component. 2019-12-06T19:46:12.243Z,1575661572.243 [CBIT](DEBUG): Initialize CBIT Component. 2019-12-06T19:46:12.244Z,1575661572.244 [logger ThreadHandler](INFO): Handler Thread ID is 427 2019-12-06T19:46:12.257Z,1575661572.257 [CBIT](DEBUG): Initialized mux pins. 2019-12-06T19:46:12.257Z,1575661572.257 [CBIT](DEBUG): Initializing the watchdog timer. 2019-12-06T19:46:12.261Z,1575661572.261 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 428 2019-12-06T19:46:12.262Z,1575661572.262 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-12-06T19:46:12.269Z,1575661572.269 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 429 2019-12-06T19:46:12.277Z,1575661572.277 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 430 2019-12-06T19:46:12.281Z,1575661572.281 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-12-06T19:46:12.281Z,1575661572.281 [CBIT](DEBUG): Initializing heartbeat. 2019-12-06T19:46:12.289Z,1575661572.289 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 431 2019-12-06T19:46:12.290Z,1575661572.290 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-12-06T19:46:12.293Z,1575661572.293 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-12-06T19:46:12.295Z,1575661572.295 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 433 2019-12-06T19:46:12.295Z,1575661572.295 [WetLabsBB2FL](INFO): Powering down 2019-12-06T19:46:12.333Z,1575661572.333 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 434 2019-12-06T19:46:12.336Z,1575661572.336 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-12-06T19:46:12.336Z,1575661572.336 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-12-06T19:46:12.337Z,1575661572.337 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-12-06T19:46:12.337Z,1575661572.337 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-12-06T19:46:12.337Z,1575661572.337 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-12-06T19:46:12.337Z,1575661572.337 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-12-06T19:46:12.338Z,1575661572.338 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-12-06T19:46:12.338Z,1575661572.338 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-12-06T19:46:12.338Z,1575661572.338 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-12-06T19:46:12.338Z,1575661572.338 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-12-06T19:46:12.338Z,1575661572.338 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-12-06T19:46:12.339Z,1575661572.339 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-12-06T19:46:12.339Z,1575661572.339 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-12-06T19:46:12.339Z,1575661572.339 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-12-06T19:46:12.339Z,1575661572.339 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-12-06T19:46:12.339Z,1575661572.339 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-12-06T19:46:12.353Z,1575661572.353 [CBIT](DEBUG): Deactivating GF circuits. 2019-12-06T19:46:12.353Z,1575661572.353 [CBIT](DEBUG): Deactivating emergency mode. 2019-12-06T19:46:12.389Z,1575661572.389 [CBIT](DEBUG): Backplane powered. 2019-12-06T19:46:12.391Z,1575661572.391 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-12-06T19:46:12.402Z,1575661572.402 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-12-06T19:46:12.433Z,1575661572.433 [MissionManager](DEBUG): 2019-12-06T19:46:12.434Z,1575661572.434 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-12-06T19:46:12.498Z,1575661572.498 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-12-06T19:46:12.499Z,1575661572.499 [Default:A.Wait](DEBUG): Construct Wait. 2019-12-06T19:46:12.501Z,1575661572.501 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-12-06T19:46:12.556Z,1575661572.556 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-12-06T19:46:12.558Z,1575661572.558 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-12-06T19:46:12.580Z,1575661572.580 [Default:E.Execute](DEBUG): Construct Execute. 2019-12-06T19:46:12.592Z,1575661572.592 [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-12-06T19:46:12.613Z,1575661572.613 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,Onboard,DAT,BPC1,ESPComponent,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-12-06T19:46:12.625Z,1575661572.625 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-12-06T19:46:12.670Z,1575661572.670 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar 2019-12-06T19:46:12.673Z,1575661572.673 [Radio_Surface](INFO): Powering up 2019-12-06T19:46:12.691Z,1575661572.691 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-12-06T19:46:12.691Z,1575661572.691 [DAT](INFO): Powering up 2019-12-06T19:46:12.691Z,1575661572.691 [DAT](DEBUG): Initializing DAT. 2019-12-06T19:46:12.725Z,1575661572.725 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-12-06T19:46:12.749Z,1575661572.749 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-12-06T19:46:12.783Z,1575661572.783 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-12-06T19:46:12.801Z,1575661572.801 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-12-06T19:46:12.803Z,1575661572.803 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-12-06T19:46:12.813Z,1575661572.813 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-12-06T19:46:12.814Z,1575661572.814 [MassServo](DEBUG): Initializing EZServoServo. 2019-12-06T19:46:12.825Z,1575661572.825 [MassServo](DEBUG): Initializing MassServo. 2019-12-06T19:46:12.826Z,1575661572.826 [RudderServo](DEBUG): Initializing EZServoServo. 2019-12-06T19:46:12.838Z,1575661572.838 [RudderServo](DEBUG): Initializing RudderServo. 2019-12-06T19:46:12.839Z,1575661572.839 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-12-06T19:46:12.851Z,1575661572.851 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-12-06T19:46:13.061Z,1575661573.061 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-12-06T19:46:13.773Z,1575661573.773 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-12-06T19:46:13.773Z,1575661573.773 [RudderServo](FAULT): Rudder failed to initialize 2019-12-06T19:46:13.773Z,1575661573.773 [RudderServo] Communications Fault, FailCount= 1 2019-12-06T19:46:13.773Z,1575661573.773 [RudderServo](ERROR): Communications Fault 2019-12-06T19:46:13.884Z,1575661573.884 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-12-06T19:46:14.046Z,1575661574.046 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-12-06T19:46:14.046Z,1575661574.046 [RudderServo](INFO): Powering down 2019-12-06T19:46:14.740Z,1575661574.740 [RudderServo](DEBUG): Initializing EZServoServo. 2019-12-06T19:46:14.858Z,1575661574.858 [RudderServo](DEBUG): Initializing RudderServo. 2019-12-06T19:46:14.862Z,1575661574.862 [CBIT](INFO): Clearing failed state for component RudderServo 2019-12-06T19:46:14.862Z,1575661574.862 [RudderServo] No Fault, FailCount= 1 2019-12-06T19:46:23.233Z,1575661583.233 [DAT](DEBUG): 2019-12-06T19:46:23.233Z,1575661583.233 [DAT](DEBUG): Teledyne Benthos DAT-900 Series 2019-12-06T19:46:24.446Z,1575661584.446 [DAT](DEBUG): MF Frequency Band 2019-12-06T19:46:24.447Z,1575661584.447 [DAT](DEBUG): Directional Acoustic Transponder version 8.12.21 2019-12-06T19:46:24.448Z,1575661584.448 [DAT](DEBUG): Dec 6 2019 19:46:31 2019-12-06T19:46:25.246Z,1575661585.246 [DAT](DEBUG): Features enabled [Bearing] 2019-12-06T19:46:25.247Z,1575661585.247 [DAT](DEBUG): CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2019-12-06T19:46:25.247Z,1575661585.247 [DAT](INFO): commRate: 800 2019-12-06T19:46:25.662Z,1575661585.662 [DAT](INFO): entering command mode 2019-12-06T19:46:26.053Z,1575661586.053 [DAT](DEBUG): checking for command mode acknowledgment 2019-12-06T19:46:26.456Z,1575661586.456 [DAT](DEBUG): checking for command mode acknowledgment 2019-12-06T19:46:26.457Z,1575661586.457 [DAT](INFO): command mode acknowledged 2019-12-06T19:46:26.457Z,1575661586.457 [DAT](INFO): setting verbose to 3 2019-12-06T19:46:26.869Z,1575661586.869 [DAT](DEBUG): checking for verbose setting acknowledgment 2019-12-06T19:46:26.870Z,1575661586.870 [DAT](INFO): set verbose to 3 2019-12-06T19:46:27.264Z,1575661587.264 [DAT](INFO): setting transmit power to 8 2019-12-06T19:46:27.668Z,1575661587.668 [DAT](DEBUG): checking for transmit power setting acknowledgment 2019-12-06T19:46:28.072Z,1575661588.072 [DAT](DEBUG): checking for transmit power setting acknowledgment 2019-12-06T19:46:28.073Z,1575661588.073 [DAT](INFO): set transmit power to 8 2019-12-06T19:46:28.478Z,1575661588.478 [DAT](INFO): setting local address to 9 2019-12-06T19:46:28.880Z,1575661588.880 [DAT](DEBUG): checking for local address setting acknowledgment 2019-12-06T19:46:29.307Z,1575661589.307 [DAT](DEBUG): checking for local address setting acknowledgment 2019-12-06T19:46:29.308Z,1575661589.308 [DAT](INFO): set local address to 9 2019-12-06T19:46:39.776Z,1575661599.776 [NAL9602](INFO): Powering up NAL9602 2019-12-06T19:46:50.682Z,1575661610.682 [NAL9602](INFO): NAL9602 initialized 2019-12-06T19:46:51.954Z,1575661611.954 [SBIT](IMPORTANT): Beginning Startup BIT 2019-12-06T19:46:51.962Z,1575661611.962 [CBIT](IMPORTANT): Beginning ground fault scan 2019-12-06T19:47:02.709Z,1575661622.709 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.012863 CHAN A1 (24V): -0.000553 CHAN A2 (12V): -0.007588 CHAN A3 (5V): -0.001701 CHAN B0 (3.3V): -0.000355 CHAN B1 (3.15aV): -0.000364 CHAN B2 (3.15bV): 0.000308 CHAN B3 (GND): 0.002898 OPEN: 0.005015 Full Scale Calc: 4.765 mA, -1.589 mA 2019-12-06T19:47:45.698Z,1575661665.698 [SBIT](IMPORTANT): SBIT PASSED 2019-12-06T19:47:45.735Z,1575661665.735 [CommandLine](IMPORTANT): got command configSet list 2019-12-06T19:47:45.735Z,1575661665.735 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-12-06T19:47:45.736Z,1575661665.736 [CommandLine](IMPORTANT): CBIT.gf24Offset=143 microampere; 2019-12-06T19:47:45.736Z,1575661665.736 [CommandLine](IMPORTANT): DAT.verbosity=3 count; 2019-12-06T19:47:45.736Z,1575661665.736 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2019-12-06T19:47:45.737Z,1575661665.737 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool; 2019-12-06T19:47:45.737Z,1575661665.737 [CommandLine](IMPORTANT): ESPComponent.sampleTimeout=0.5 minute; 2019-12-06T19:47:45.737Z,1575661665.737 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=1 bool; 2019-12-06T19:47:45.737Z,1575661665.737 [CommandLine](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool; 2019-12-06T19:47:45.737Z,1575661665.737 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=198 cubic_centimeter; 2019-12-06T19:47:45.737Z,1575661665.737 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter; 2019-12-06T19:47:45.737Z,1575661665.737 [CommandLine](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool; 2019-12-06T19:47:46.149Z,1575661666.149 [MissionManager](IMPORTANT): Started mission Startup 2019-12-06T19:47:46.149Z,1575661666.149 [Startup] Running Loop=1 2019-12-06T19:47:46.149Z,1575661666.149 [Startup](DEBUG): Aggregate::initialize Startup 2019-12-06T19:47:46.150Z,1575661666.150 [Startup:A.GoToSurface] Running Loop=1 2019-12-06T19:47:46.150Z,1575661666.150 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-06T19:47:46.150Z,1575661666.150 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-06T19:47:46.151Z,1575661666.151 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-06T19:47:46.151Z,1575661666.151 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-06T19:47:46.151Z,1575661666.151 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-06T19:47:46.152Z,1575661666.152 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-06T19:47:46.153Z,1575661666.153 [Startup:StartupSatComms] Running Loop=1 2019-12-06T19:47:46.154Z,1575661666.154 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-12-06T19:47:46.154Z,1575661666.154 [Startup:StartupSatComms:A] Running Loop=1 2019-12-06T19:47:46.570Z,1575661666.570 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-12-06T19:48:45.015Z,1575661725.015 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005011 2019-12-06T19:48:46.270Z,1575661726.270 [Startup:StartupSatComms:A](INFO): Timed out from 2019-12-06T19:47:46.2Z 2019-12-06T19:48:46.270Z,1575661726.270 [Startup:StartupSatComms:A] Stopped 2019-12-06T19:48:46.270Z,1575661726.270 [Startup:StartupSatComms:B] Running Loop=1 2019-12-06T19:48:46.668Z,1575661726.668 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-12-06T19:48:53.405Z,1575661733.405 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20191206T192139/Express0011.lzma 2019-12-06T19:48:55.410Z,1575661735.410 [DataOverHttps](INFO): Moved sent file to Logs/20191206T192139/Express0011.lzma.bak 2019-12-06T19:48:55.411Z,1575661735.411 [DataOverHttps](INFO): SBD MOMSN=12124587 2019-12-06T19:49:11.950Z,1575661751.950 [DataOverHttps](INFO): Sending 888 bytes from file Logs/20191206T194602/Express0001.lzma 2019-12-06T19:49:12.528Z,1575661752.528 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-12-06T19:49:12.529Z,1575661752.529 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-06T19:49:12.543Z,1575661752.543 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-06T19:49:12.953Z,1575661752.953 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-06T19:49:12.953Z,1575661752.953 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-12-06T19:49:13.954Z,1575661753.954 [DataOverHttps](INFO): Moved sent file to Logs/20191206T194602/Express0001.lzma.bak 2019-12-06T19:49:13.954Z,1575661753.954 [DataOverHttps](INFO): SBD MOMSN=12124592 2019-12-06T19:49:15.381Z,1575661755.381 [Startup:StartupSatComms:B] Stopped 2019-12-06T19:49:15.382Z,1575661755.382 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-12-06T19:49:15.382Z,1575661755.382 [Startup:StartupSatComms] Stopped 2019-12-06T19:49:15.382Z,1575661755.382 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-12-06T19:49:15.382Z,1575661755.382 [Startup](INFO): Completed Startup 2019-12-06T19:49:15.383Z,1575661755.383 [MissionManager](INFO): Startup is completed. 2019-12-06T19:49:15.383Z,1575661755.383 [MissionManager](INFO): Uninitializing Mission Startup 2019-12-06T19:49:15.383Z,1575661755.383 [Startup] Stopped 2019-12-06T19:49:15.383Z,1575661755.383 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-12-06T19:49:15.383Z,1575661755.383 [Startup:A.GoToSurface] Stopped 2019-12-06T19:49:15.383Z,1575661755.383 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-06T19:49:15.778Z,1575661755.778 [MissionManager](IMPORTANT): Started mission Default 2019-12-06T19:49:15.778Z,1575661755.778 [Default] Running Loop=1 2019-12-06T19:49:15.778Z,1575661755.778 [Default](DEBUG): Aggregate::initialize Default 2019-12-06T19:49:15.778Z,1575661755.778 [Default:B.GoToSurface] Running Loop=1 2019-12-06T19:49:15.778Z,1575661755.778 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-06T19:49:15.778Z,1575661755.778 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-06T19:49:15.779Z,1575661755.779 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-06T19:49:15.779Z,1575661755.779 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-06T19:49:15.779Z,1575661755.779 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-06T19:49:15.780Z,1575661755.780 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-06T19:49:15.780Z,1575661755.780 [Default:A.Wait] Running Loop=1 2019-12-06T19:49:15.780Z,1575661755.780 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-12-06T19:49:29.088Z,1575661769.088 [Default:A.Wait](INFO): Done Waiting. 2019-12-06T19:49:29.088Z,1575661769.088 [Default:A.Wait] Stopped 2019-12-06T19:49:29.088Z,1575661769.088 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-12-06T19:49:29.491Z,1575661769.491 [Default:CheckIn] Running Loop=1 2019-12-06T19:49:29.491Z,1575661769.491 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-06T19:49:29.492Z,1575661769.492 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-06T19:49:29.911Z,1575661769.911 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-12-06T19:51:54.102Z,1575661914.102 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-06T19:52:13.536Z,1575661933.536 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-12-06T19:52:13.537Z,1575661933.537 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-06T19:52:13.566Z,1575661933.566 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-06T19:52:13.953Z,1575661933.953 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-06T19:52:13.953Z,1575661933.953 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-12-06T19:53:35.543Z,1575662015.543 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-12-06T19:53:35.546Z,1575662015.546 [BPC1](INFO): Received data from all battery sticks. 2019-12-06T19:54:29.670Z,1575662069.670 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-06T19:49:29.5Z 2019-12-06T19:54:29.670Z,1575662069.670 [Default:CheckIn:Read_GPS] Stopped 2019-12-06T19:54:29.670Z,1575662069.670 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-06T19:54:30.070Z,1575662070.070 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-12-06T19:54:37.241Z,1575662077.241 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20191206T194602/Courier0004.lzma 2019-12-06T19:54:39.246Z,1575662079.246 [DataOverHttps](INFO): Moved sent file to Logs/20191206T194602/Courier0004.lzma.bak 2019-12-06T19:54:39.246Z,1575662079.246 [DataOverHttps](INFO): SBD MOMSN=12124632 2019-12-06T19:55:05.173Z,1575662105.173 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20191206T194602/Express0005.lzma 2019-12-06T19:55:07.178Z,1575662107.178 [DataOverHttps](INFO): Moved sent file to Logs/20191206T194602/Express0005.lzma.bak 2019-12-06T19:55:07.178Z,1575662107.178 [DataOverHttps](INFO): SBD MOMSN=12124655 2019-12-06T19:55:08.449Z,1575662108.449 [Default:CheckIn:Read_Iridium] Stopped 2019-12-06T19:55:08.450Z,1575662108.450 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-06T19:55:08.450Z,1575662108.450 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-06T19:55:14.508Z,1575662114.508 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-12-06T19:55:14.508Z,1575662114.508 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-06T19:55:14.519Z,1575662114.519 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-06T19:55:14.938Z,1575662114.938 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-06T19:55:14.938Z,1575662114.938 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-12-06T19:56:51.850Z,1575662211.850 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-12-06T19:56:51.850Z,1575662211.850 [NAL9602] Data Fault, FailCount= 1 2019-12-06T19:56:51.850Z,1575662211.850 [NAL9602](ERROR): Data Fault 2019-12-06T19:56:51.903Z,1575662211.903 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-06T19:56:52.250Z,1575662212.250 [NAL9602](INFO): Powering down 2019-12-06T19:56:53.096Z,1575662213.096 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-06T19:56:53.096Z,1575662213.096 [NAL9602] No Fault, FailCount= 1 2019-12-06T19:57:22.554Z,1575662242.554 [NAL9602](INFO): Powering up NAL9602 2019-12-06T19:57:33.458Z,1575662253.458 [NAL9602](INFO): NAL9602 initialized 2019-12-06T19:58:15.500Z,1575662295.500 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-12-06T19:58:15.500Z,1575662295.500 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-06T19:58:15.510Z,1575662295.510 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-06T19:58:15.918Z,1575662295.918 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-06T19:58:15.918Z,1575662295.918 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4