2019-05-28T04:47:59.257Z,1559018879.257 [Supervisor](DEBUG): Initializing supervisor. 2019-05-28T04:47:59.260Z,1559018879.260 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-05-28T04:47:59.261Z,1559018879.261 [SyncHandler](INFO): Protected caller Thread ID is 1164 2019-05-28T04:47:59.261Z,1559018879.261 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-05-28T04:47:59.262Z,1559018879.262 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-05-28T04:47:59.262Z,1559018879.262 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1165 2019-05-28T04:47:59.265Z,1559018879.265 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-05-28T04:47:59.276Z,1559018879.276 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-05-28T04:47:59.277Z,1559018879.277 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-05-28T04:47:59.278Z,1559018879.278 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1166 2019-05-28T04:47:59.279Z,1559018879.279 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-05-28T04:47:59.281Z,1559018879.281 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-05-28T04:47:59.281Z,1559018879.281 [logger ThreadHandler](INFO): Protected caller Thread ID is 1167 2019-05-28T04:47:59.283Z,1559018879.283 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-05-28T04:47:59.284Z,1559018879.284 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-05-28T04:47:59.287Z,1559018879.287 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-05-28T04:47:59.554Z,1559018879.554 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-05-28T04:47:59.555Z,1559018879.555 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-05-28T04:47:59.639Z,1559018879.639 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-05-28T04:48:00.080Z,1559018880.080 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-05-28T04:48:00.081Z,1559018880.081 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-05-28T04:48:00.418Z,1559018880.418 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-05-28T04:48:00.419Z,1559018880.419 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-05-28T04:48:00.515Z,1559018880.515 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-05-28T04:48:00.516Z,1559018880.516 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-05-28T04:48:00.903Z,1559018880.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-05-28T04:48:00.903Z,1559018880.903 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-05-28T04:48:01.263Z,1559018881.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-05-28T04:48:01.264Z,1559018881.264 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-05-28T04:48:01.941Z,1559018881.941 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-05-28T04:48:01.942Z,1559018881.942 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-05-28T04:48:02.046Z,1559018882.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-05-28T04:48:02.047Z,1559018882.047 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-05-28T04:48:02.147Z,1559018882.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-05-28T04:48:02.148Z,1559018882.148 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-05-28T04:48:02.729Z,1559018882.729 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-05-28T04:48:02.730Z,1559018882.730 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-05-28T04:48:03.119Z,1559018883.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-05-28T04:48:03.120Z,1559018883.120 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-05-28T04:48:03.315Z,1559018883.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-05-28T04:48:03.315Z,1559018883.315 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-05-28T04:48:03.461Z,1559018883.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-05-28T04:48:03.462Z,1559018883.462 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-05-28T04:48:03.611Z,1559018883.611 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-05-28T04:48:03.613Z,1559018883.613 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2019-05-28T04:48:03.615Z,1559018883.615 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2019-05-28T04:48:03.707Z,1559018883.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2019-05-28T04:48:03.791Z,1559018883.791 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2019-05-28T04:48:03.893Z,1559018883.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2019-05-28T04:48:03.978Z,1559018883.978 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2019-05-28T04:48:04.072Z,1559018884.072 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2019-05-28T04:48:04.172Z,1559018884.172 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2019-05-28T04:48:04.378Z,1559018884.378 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2019-05-28T04:48:04.455Z,1559018884.455 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2019-05-28T04:48:04.625Z,1559018884.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2019-05-28T04:48:04.760Z,1559018884.760 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2019-05-28T04:48:04.880Z,1559018884.880 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2019-05-28T04:48:05.110Z,1559018885.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-05-28T04:48:05.112Z,1559018885.112 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2019-05-28T04:48:05.112Z,1559018885.112 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-05-28T04:48:05.127Z,1559018885.127 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-05-28T04:48:05.216Z,1559018885.216 [VerticalControl](DEBUG): Construct VerticalControl. 2019-05-28T04:48:05.330Z,1559018885.330 [VerticalControl] Loaded 2019-05-28T04:48:05.330Z,1559018885.330 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-05-28T04:48:05.331Z,1559018885.331 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-05-28T04:48:05.401Z,1559018885.401 [HorizontalControl] Loaded 2019-05-28T04:48:05.401Z,1559018885.401 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-05-28T04:48:05.402Z,1559018885.402 [SpeedControl](DEBUG): Construct SpeedControl. 2019-05-28T04:48:05.408Z,1559018885.408 [SpeedControl] Loaded 2019-05-28T04:48:05.408Z,1559018885.408 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-05-28T04:48:05.409Z,1559018885.409 [LoopControl](DEBUG): Construct LoopControl. 2019-05-28T04:48:05.409Z,1559018885.409 [LoopControl] Loaded 2019-05-28T04:48:05.409Z,1559018885.409 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-05-28T04:48:05.410Z,1559018885.410 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-05-28T04:48:05.410Z,1559018885.410 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-05-28T04:48:05.436Z,1559018885.436 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-05-28T04:48:05.436Z,1559018885.436 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-05-28T04:48:05.568Z,1559018885.568 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-05-28T04:48:05.568Z,1559018885.568 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-05-28T04:48:05.698Z,1559018885.698 [BuoyancyServo] Loaded 2019-05-28T04:48:05.698Z,1559018885.698 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-05-28T04:48:05.709Z,1559018885.709 [ElevatorServo] Loaded 2019-05-28T04:48:05.709Z,1559018885.709 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-05-28T04:48:05.720Z,1559018885.720 [MassServo] Loaded 2019-05-28T04:48:05.721Z,1559018885.721 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-05-28T04:48:05.732Z,1559018885.732 [RudderServo] Loaded 2019-05-28T04:48:05.732Z,1559018885.732 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-05-28T04:48:05.743Z,1559018885.743 [ThrusterServo] Loaded 2019-05-28T04:48:05.743Z,1559018885.743 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-05-28T04:48:05.744Z,1559018885.744 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-05-28T04:48:05.744Z,1559018885.744 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-05-28T04:48:05.872Z,1559018885.872 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-05-28T04:48:05.872Z,1559018885.872 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-05-28T04:48:05.893Z,1559018885.893 [NavChart] Loaded 2019-05-28T04:48:05.893Z,1559018885.893 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-05-28T04:48:05.897Z,1559018885.897 [UniversalFixResidualReporter] Loaded 2019-05-28T04:48:05.898Z,1559018885.898 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-05-28T04:48:05.898Z,1559018885.898 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-05-28T04:48:05.899Z,1559018885.899 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-05-28T04:48:06.019Z,1559018886.019 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-05-28T04:48:06.020Z,1559018886.020 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-05-28T04:48:06.718Z,1559018886.718 [AHRS_M2] Loaded 2019-05-28T04:48:06.718Z,1559018886.718 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-05-28T04:48:06.817Z,1559018886.817 [DataOverHttps] Loaded 2019-05-28T04:48:06.817Z,1559018886.817 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-05-28T04:48:06.818Z,1559018886.818 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0 2019-05-28T04:48:06.819Z,1559018886.819 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1250 2019-05-28T04:48:06.840Z,1559018886.840 [Depth_Keller] Loaded 2019-05-28T04:48:06.840Z,1559018886.840 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-05-28T04:48:06.845Z,1559018886.845 [DropWeight] Loaded 2019-05-28T04:48:06.846Z,1559018886.846 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-05-28T04:48:07.416Z,1559018887.416 [NAL9602] Loaded 2019-05-28T04:48:07.417Z,1559018887.417 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-05-28T04:48:07.520Z,1559018887.520 [Onboard] Loaded 2019-05-28T04:48:07.520Z,1559018887.520 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-05-28T04:48:07.524Z,1559018887.524 [Radio_Surface] Loaded 2019-05-28T04:48:07.524Z,1559018887.524 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-05-28T04:48:07.534Z,1559018887.534 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0 2019-05-28T04:48:07.534Z,1559018887.534 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1251 2019-05-28T04:48:07.705Z,1559018887.705 [DAT] Loaded 2019-05-28T04:48:07.706Z,1559018887.706 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-05-28T04:48:09.256Z,1559018889.256 [BPC1] Loaded 2019-05-28T04:48:09.257Z,1559018889.257 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-05-28T04:48:09.257Z,1559018889.257 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-05-28T04:48:09.258Z,1559018889.258 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-05-28T04:48:09.317Z,1559018889.317 [DepthRateCalculator] Loaded 2019-05-28T04:48:09.317Z,1559018889.317 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-05-28T04:48:09.322Z,1559018889.322 [PitchRateCalculator] Loaded 2019-05-28T04:48:09.322Z,1559018889.322 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-05-28T04:48:09.334Z,1559018889.334 [SpeedCalculator] Loaded 2019-05-28T04:48:09.335Z,1559018889.335 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-05-28T04:48:09.357Z,1559018889.357 [TempGradientCalculator] Loaded 2019-05-28T04:48:09.357Z,1559018889.357 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-05-28T04:48:09.362Z,1559018889.362 [YawRateCalculator] Loaded 2019-05-28T04:48:09.362Z,1559018889.362 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-05-28T04:48:09.392Z,1559018889.392 [ElevatorOffsetCalculator] Loaded 2019-05-28T04:48:09.393Z,1559018889.393 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-05-28T04:48:09.393Z,1559018889.393 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-05-28T04:48:09.394Z,1559018889.394 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-05-28T04:48:09.663Z,1559018889.663 [Aanderaa_O2] Loaded 2019-05-28T04:48:09.663Z,1559018889.663 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2019-05-28T04:48:09.748Z,1559018889.748 [CTD_NeilBrown] Loaded 2019-05-28T04:48:09.749Z,1559018889.749 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2019-05-28T04:48:09.750Z,1559018889.750 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409AF4E0 2019-05-28T04:48:09.750Z,1559018889.750 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1252 2019-05-28T04:48:09.760Z,1559018889.760 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-05-28T04:48:09.765Z,1559018889.765 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-05-28T04:48:09.766Z,1559018889.766 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-05-28T04:48:09.771Z,1559018889.771 [CTD_Seabird](INFO): created writer for : depth 2019-05-28T04:48:09.772Z,1559018889.772 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-05-28T04:48:09.777Z,1559018889.777 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-05-28T04:48:09.778Z,1559018889.778 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-05-28T04:48:09.783Z,1559018889.783 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-05-28T04:48:09.783Z,1559018889.783 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-05-28T04:48:09.788Z,1559018889.788 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-05-28T04:48:09.789Z,1559018889.789 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-05-28T04:48:09.794Z,1559018889.794 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-05-28T04:48:09.795Z,1559018889.795 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-05-28T04:48:09.800Z,1559018889.800 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-05-28T04:48:09.827Z,1559018889.827 [CTD_Seabird] Loaded 2019-05-28T04:48:09.828Z,1559018889.828 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-05-28T04:48:09.829Z,1559018889.829 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DF4E0 2019-05-28T04:48:09.829Z,1559018889.829 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1253 2019-05-28T04:48:09.861Z,1559018889.861 [ESPComponent] Loaded 2019-05-28T04:48:09.861Z,1559018889.861 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-05-28T04:48:09.875Z,1559018889.875 [PAR_Licor] Loaded 2019-05-28T04:48:09.875Z,1559018889.875 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-05-28T04:48:09.924Z,1559018889.924 [WetLabsBB2FL] Loaded 2019-05-28T04:48:09.924Z,1559018889.924 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-05-28T04:48:09.925Z,1559018889.925 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0F4E0 2019-05-28T04:48:09.926Z,1559018889.926 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1254 2019-05-28T04:48:09.926Z,1559018889.926 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-05-28T04:48:09.927Z,1559018889.927 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-05-28T04:48:09.976Z,1559018889.976 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-05-28T04:48:09.977Z,1559018889.977 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-05-28T04:48:10.336Z,1559018890.336 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-05-28T04:48:10.338Z,1559018890.338 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-05-28T04:48:10.503Z,1559018890.503 [SBIT](DEBUG): Construct Startup Built In Test. 2019-05-28T04:48:10.514Z,1559018890.514 [SBIT] Loaded 2019-05-28T04:48:10.515Z,1559018890.515 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-05-28T04:48:10.515Z,1559018890.515 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-05-28T04:48:10.527Z,1559018890.527 [IBIT] Loaded 2019-05-28T04:48:10.527Z,1559018890.527 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-05-28T04:48:10.531Z,1559018890.531 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-05-28T04:48:10.670Z,1559018890.670 [CBIT] Loaded 2019-05-28T04:48:10.670Z,1559018890.670 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-05-28T04:48:10.671Z,1559018890.671 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-05-28T04:48:10.675Z,1559018890.675 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-05-28T04:48:10.676Z,1559018890.676 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-05-28T04:48:10.682Z,1559018890.682 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-05-28T04:48:10.683Z,1559018890.683 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0 2019-05-28T04:48:10.684Z,1559018890.684 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1255 2019-05-28T04:48:10.688Z,1559018890.688 [Supervisor](INFO): Main Thread ID is 1163 2019-05-28T04:48:10.688Z,1559018890.688 [Supervisor](DEBUG): Running supervisor. 2019-05-28T04:48:10.689Z,1559018890.689 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1256 2019-05-28T04:48:10.691Z,1559018890.691 [controlThread ThreadHandler](INFO): Handler Thread ID is 1257 2019-05-28T04:48:10.692Z,1559018890.692 [controlThread](DEBUG): Initializing ControlThread 2019-05-28T04:48:10.693Z,1559018890.693 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-05-28T04:48:10.694Z,1559018890.694 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-05-28T04:48:10.695Z,1559018890.695 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-05-28T04:48:10.695Z,1559018890.695 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-05-28T04:48:10.697Z,1559018890.697 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-05-28T04:48:10.698Z,1559018890.698 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-05-28T04:48:10.701Z,1559018890.701 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-05-28T04:48:10.701Z,1559018890.701 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-05-28T04:48:10.702Z,1559018890.702 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-05-28T04:48:10.702Z,1559018890.702 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-05-28T04:48:10.703Z,1559018890.703 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-05-28T04:48:10.703Z,1559018890.703 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-05-28T04:48:10.707Z,1559018890.707 [SBIT](INFO): Initialize SBIT Component. 2019-05-28T04:48:10.707Z,1559018890.707 [SBIT](IMPORTANT): git: 2019-05-21 2019-05-28T04:48:10.708Z,1559018890.708 [SBIT](INFO): git hash: d33b11e57afc4926c4e35bc3081773f5ba5b446b 2019-05-28T04:48:10.708Z,1559018890.708 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-05-28T04:48:10.709Z,1559018890.709 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 2019-05-28T04:48:10.727Z,1559018890.727 [SBIT](INFO): Beginning SBIT in 23.000000 seconds. 2019-05-28T04:48:10.728Z,1559018890.728 [logger ThreadHandler](INFO): Handler Thread ID is 1258 2019-05-28T04:48:10.755Z,1559018890.755 [IBIT](INFO): Initialize IBIT Component. 2019-05-28T04:48:10.756Z,1559018890.756 [CBIT](DEBUG): Initialize CBIT Component. 2019-05-28T04:48:10.757Z,1559018890.757 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1259 2019-05-28T04:48:10.758Z,1559018890.758 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-05-28T04:48:10.767Z,1559018890.767 [CBIT](DEBUG): Initialized mux pins. 2019-05-28T04:48:10.767Z,1559018890.767 [CBIT](DEBUG): Initializing the watchdog timer. 2019-05-28T04:48:10.768Z,1559018890.768 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1260 2019-05-28T04:48:10.775Z,1559018890.775 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1261 2019-05-28T04:48:10.776Z,1559018890.776 [CTD_NeilBrown](INFO): Powering down 2019-05-28T04:48:10.795Z,1559018890.795 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-05-28T04:48:10.795Z,1559018890.795 [CBIT](DEBUG): Initializing heartbeat. 2019-05-28T04:48:10.803Z,1559018890.803 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1262 2019-05-28T04:48:10.804Z,1559018890.804 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-05-28T04:48:10.809Z,1559018890.809 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1264 2019-05-28T04:48:10.810Z,1559018890.810 [WetLabsBB2FL](INFO): Powering down 2019-05-28T04:48:10.814Z,1559018890.814 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-05-28T04:48:10.835Z,1559018890.835 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1265 2019-05-28T04:48:10.844Z,1559018890.844 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-05-28T04:48:10.844Z,1559018890.844 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-05-28T04:48:10.845Z,1559018890.845 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-05-28T04:48:10.845Z,1559018890.845 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-05-28T04:48:10.845Z,1559018890.845 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-05-28T04:48:10.845Z,1559018890.845 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-05-28T04:48:10.845Z,1559018890.845 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-05-28T04:48:10.845Z,1559018890.845 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-05-28T04:48:10.846Z,1559018890.846 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-05-28T04:48:10.846Z,1559018890.846 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-05-28T04:48:10.846Z,1559018890.846 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-05-28T04:48:10.846Z,1559018890.846 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-05-28T04:48:10.846Z,1559018890.846 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-05-28T04:48:10.847Z,1559018890.847 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-05-28T04:48:10.847Z,1559018890.847 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-05-28T04:48:10.847Z,1559018890.847 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-05-28T04:48:10.867Z,1559018890.867 [CBIT](DEBUG): Deactivating GF circuits. 2019-05-28T04:48:10.867Z,1559018890.867 [CBIT](DEBUG): Deactivating emergency mode. 2019-05-28T04:48:10.903Z,1559018890.903 [CBIT](DEBUG): Backplane powered. 2019-05-28T04:48:10.904Z,1559018890.904 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-05-28T04:48:10.936Z,1559018890.936 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-05-28T04:48:10.946Z,1559018890.946 [MissionManager](DEBUG): 2019-05-28T04:48:10.947Z,1559018890.947 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-05-28T04:48:11.003Z,1559018891.003 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-05-28T04:48:11.004Z,1559018891.004 [Default:A.Wait](DEBUG): Construct Wait. 2019-05-28T04:48:11.006Z,1559018891.006 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-05-28T04:48:11.045Z,1559018891.045 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-05-28T04:48:11.048Z,1559018891.048 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-05-28T04:48:11.082Z,1559018891.082 [Default:E.Execute](DEBUG): Construct Execute. 2019-05-28T04:48:11.092Z,1559018891.092 [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-05-28T04:48:11.097Z,1559018891.097 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,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, 2019-05-28T04:48:11.115Z,1559018891.115 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-05-28T04:48:11.171Z,1559018891.171 [Radio_Surface](INFO): Powering up 2019-05-28T04:48:11.269Z,1559018891.269 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2019-05-28T04:48:11.296Z,1559018891.296 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-05-28T04:48:11.296Z,1559018891.296 [DAT](INFO): Powering up 2019-05-28T04:48:11.297Z,1559018891.297 [DAT](DEBUG): Initializing DAT. 2019-05-28T04:48:11.371Z,1559018891.371 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-05-28T04:48:11.391Z,1559018891.391 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-05-28T04:48:11.480Z,1559018891.480 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-05-28T04:48:11.487Z,1559018891.487 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-05-28T04:48:11.488Z,1559018891.488 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-05-28T04:48:11.499Z,1559018891.499 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-05-28T04:48:11.500Z,1559018891.500 [MassServo](DEBUG): Initializing EZServoServo. 2019-05-28T04:48:11.511Z,1559018891.511 [MassServo](DEBUG): Initializing MassServo. 2019-05-28T04:48:11.512Z,1559018891.512 [RudderServo](DEBUG): Initializing EZServoServo. 2019-05-28T04:48:11.523Z,1559018891.523 [RudderServo](DEBUG): Initializing RudderServo. 2019-05-28T04:48:11.524Z,1559018891.524 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-05-28T04:48:11.535Z,1559018891.535 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-05-28T04:48:14.595Z,1559018894.595 [Aanderaa_O2](INFO): Powering down 2019-05-28T04:48:22.914Z,1559018902.914 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006356 2019-05-28T04:48:24.647Z,1559018904.647 [DAT](INFO): setting local address to 2 2019-05-28T04:48:25.051Z,1559018905.051 [DAT](INFO): set local address to 2 2019-05-28T04:48:34.383Z,1559018914.383 [SBIT](IMPORTANT): Beginning Startup BIT 2019-05-28T04:48:34.387Z,1559018914.387 [CBIT](IMPORTANT): Beginning ground fault scan 2019-05-28T04:48:37.433Z,1559018917.433 [NAL9602](INFO): Powering up NAL9602 2019-05-28T04:48:45.667Z,1559018925.667 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.002276 CHAN A1 (24V): -0.016369 CHAN A2 (12V): -0.001780 CHAN A3 (5V): -0.001707 CHAN B0 (3.3V): 0.000034 CHAN B1 (3.15aV): -0.000514 CHAN B2 (3.15bV): 4.767929 CHAN B3 (GND): -0.000892 OPEN: 0.005306 Full Scale Calc: 4.765 mA, -1.589 mA 2019-05-28T04:48:48.308Z,1559018928.308 [NAL9602](INFO): NAL9602 initialized 2019-05-28T04:48:49.131Z,1559018929.131 [NAL9602](DEBUG): Fix Requested 2019-05-28T04:49:10.252Z,1559018950.252 [CommandLine](IMPORTANT): got command gfscan 2019-05-28T04:49:10.342Z,1559018950.342 [CBIT](IMPORTANT): Beginning ground fault scan 2019-05-28T04:49:21.408Z,1559018961.408 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.000208 CHAN A1 (24V): -0.016783 CHAN A2 (12V): -0.001862 CHAN A3 (5V): -0.001498 CHAN B0 (3.3V): 0.000088 CHAN B1 (3.15aV): 0.000157 CHAN B2 (3.15bV): -0.000185 CHAN B3 (GND): 4.792929 OPEN: 0.005700 Full Scale Calc: 4.765 mA, -1.589 mA 2019-05-28T04:49:27.822Z,1559018967.822 [SBIT](IMPORTANT): SBIT PASSED 2019-05-28T04:49:27.873Z,1559018967.873 [CommandLine](IMPORTANT): got command configSet list 2019-05-28T04:49:27.873Z,1559018967.873 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-05-28T04:49:27.874Z,1559018967.874 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=0 count; 2019-05-28T04:49:27.874Z,1559018967.874 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour; 2019-05-28T04:49:27.874Z,1559018967.874 [CommandLine](IMPORTANT): CBIT.abortDepth=296 meter; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): CBIT.stopDepth=288 meter; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): Express linearApproximation DAT.range 5.000000 meter; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool; 2019-05-28T04:49:27.875Z,1559018967.875 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-31 millimeter; 2019-05-28T04:49:27.876Z,1559018967.876 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=30 millimeter; 2019-05-28T04:49:28.217Z,1559018968.217 [MissionManager](IMPORTANT): Started mission Startup 2019-05-28T04:49:28.217Z,1559018968.217 [Startup] Running Loop=1 2019-05-28T04:49:28.217Z,1559018968.217 [Startup](DEBUG): Aggregate::initialize Startup 2019-05-28T04:49:28.217Z,1559018968.217 [Startup:A.GoToSurface] Running Loop=1 2019-05-28T04:49:28.217Z,1559018968.217 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-05-28T04:49:28.218Z,1559018968.218 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-05-28T04:49:28.219Z,1559018968.219 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-05-28T04:49:28.220Z,1559018968.220 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-05-28T04:49:28.220Z,1559018968.220 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-05-28T04:49:28.220Z,1559018968.220 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-05-28T04:49:28.222Z,1559018968.222 [Startup:StartupSatComms] Running Loop=1 2019-05-28T04:49:28.222Z,1559018968.222 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-05-28T04:49:28.222Z,1559018968.222 [Startup:StartupSatComms:A] Running Loop=1 2019-05-28T04:49:28.621Z,1559018968.621 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-05-28T04:49:35.400Z,1559018975.400 [CommandLine](IMPORTANT): got command gfscan 2019-05-28T04:49:35.506Z,1559018975.506 [CBIT](IMPORTANT): Beginning ground fault scan 2019-05-28T04:49:46.454Z,1559018986.454 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.000905 CHAN A1 (24V): -0.016242 CHAN A2 (12V): -0.002041 CHAN A3 (5V): -0.001341 CHAN B0 (3.3V): 0.000173 CHAN B1 (3.15aV): -0.000285 CHAN B2 (3.15bV): -0.000017 CHAN B3 (GND): -0.000171 OPEN: -0.000011 Full Scale Calc: 4.765 mA, -1.589 mA 2019-05-28T04:50:28.464Z,1559019028.464 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-28T04:49:28.2Z 2019-05-28T04:50:28.464Z,1559019028.464 [Startup:StartupSatComms:A] Stopped 2019-05-28T04:50:28.464Z,1559019028.464 [Startup:StartupSatComms:B] Running Loop=1 2019-05-28T04:50:28.813Z,1559019028.813 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-05-28T04:50:33.601Z,1559019033.601 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190524T202725/Courier0016.lzma 2019-05-28T04:50:34.404Z,1559019034.404 [DataOverHttps](INFO): Moved sent file to Logs/20190524T202725/Courier0016.lzma.bak 2019-05-28T04:50:34.404Z,1559019034.404 [DataOverHttps](INFO): SBD MOMSN=11202439 2019-05-28T04:50:40.565Z,1559019040.565 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-05-28T04:50:45.110Z,1559019045.110 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190524T205426/Courier0004.lzma 2019-05-28T04:50:45.916Z,1559019045.916 [DataOverHttps](INFO): Moved sent file to Logs/20190524T205426/Courier0004.lzma.bak 2019-05-28T04:50:45.916Z,1559019045.916 [DataOverHttps](INFO): SBD MOMSN=11202441 2019-05-28T04:50:56.562Z,1559019056.562 [DataOverHttps](INFO): Sending 101 bytes from file Logs/20190524T202725/Express0017.lzma 2019-05-28T04:50:57.368Z,1559019057.368 [DataOverHttps](INFO): Moved sent file to Logs/20190524T202725/Express0017.lzma.bak 2019-05-28T04:50:57.368Z,1559019057.368 [DataOverHttps](INFO): SBD MOMSN=11202444 2019-05-28T04:51:07.953Z,1559019067.953 [DataOverHttps](INFO): Sending 720 bytes from file Logs/20190524T205119/Express0001.lzma 2019-05-28T04:51:08.804Z,1559019068.804 [DataOverHttps](INFO): Moved sent file to Logs/20190524T205119/Express0001.lzma.bak 2019-05-28T04:51:08.804Z,1559019068.804 [DataOverHttps](INFO): SBD MOMSN=11202447 2019-05-28T04:51:10.863Z,1559019070.863 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-05-28T04:51:10.863Z,1559019070.863 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-05-28T04:51:10.890Z,1559019070.890 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-05-28T04:51:11.268Z,1559019071.268 [CBIT](INFO): Cl