2017-09-09T18:56:53.019Z,1504983413.019 [Supervisor](DEBUG): Initializing supervisor. 2017-09-09T18:56:53.022Z,1504983413.022 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2017-09-09T18:56:53.022Z,1504983413.022 [SyncHandler](INFO): Protected caller Thread ID is 770 2017-09-09T18:56:53.023Z,1504983413.023 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-09-09T18:56:53.024Z,1504983413.024 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2017-09-09T18:56:53.024Z,1504983413.024 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 771 2017-09-09T18:56:53.028Z,1504983413.028 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-09-09T18:56:53.043Z,1504983413.043 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-09-09T18:56:53.044Z,1504983413.044 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2017-09-09T18:56:53.044Z,1504983413.044 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 772 2017-09-09T18:56:53.045Z,1504983413.045 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-09-09T18:56:53.046Z,1504983413.046 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2017-09-09T18:56:53.047Z,1504983413.047 [logger ThreadHandler](INFO): Protected caller Thread ID is 773 2017-09-09T18:56:53.050Z,1504983413.050 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-09-09T18:56:53.050Z,1504983413.050 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-09-09T18:56:53.053Z,1504983413.053 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-09-09T18:56:53.262Z,1504983413.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-09-09T18:56:53.263Z,1504983413.263 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-09-09T18:56:53.408Z,1504983413.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-09-09T18:56:53.409Z,1504983413.409 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-09-09T18:56:53.805Z,1504983413.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-09-09T18:56:53.806Z,1504983413.806 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-09-09T18:56:53.961Z,1504983413.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-09-09T18:56:53.962Z,1504983413.962 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-09-09T18:56:54.049Z,1504983414.049 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-09-09T18:56:54.278Z,1504983414.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-09-09T18:56:54.280Z,1504983414.280 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-09-09T18:56:54.391Z,1504983414.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-09-09T18:56:54.392Z,1504983414.392 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-09-09T18:56:54.737Z,1504983414.737 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-09-09T18:56:54.738Z,1504983414.738 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-09-09T18:56:55.177Z,1504983415.177 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-09-09T18:56:55.178Z,1504983415.178 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-09-09T18:56:55.552Z,1504983415.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-09-09T18:56:55.553Z,1504983415.553 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-09-09T18:56:56.201Z,1504983416.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-09-09T18:56:59.924Z,1504983419.924 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-09-09T18:57:00.201Z,1504983420.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-09-09T18:57:00.202Z,1504983420.202 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-09-09T18:57:00.311Z,1504983420.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-09-09T18:57:00.312Z,1504983420.312 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-09-09T18:57:00.885Z,1504983420.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-09-09T18:57:00.886Z,1504983420.886 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-09-09T18:57:04.930Z,1504983424.930 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-09-09T18:57:04.932Z,1504983424.932 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2017-09-09T18:57:04.935Z,1504983424.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2017-09-09T18:57:05.242Z,1504983425.242 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-09-09T18:57:05.243Z,1504983425.243 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2017-09-09T18:57:05.352Z,1504983425.352 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2017-09-09T18:57:05.452Z,1504983425.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2017-09-09T18:57:05.563Z,1504983425.563 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2017-09-09T18:57:05.656Z,1504983425.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2017-09-09T18:57:05.798Z,1504983425.798 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2017-09-09T18:57:05.974Z,1504983425.974 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2017-09-09T18:57:07.662Z,1504983427.662 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2017-09-09T18:57:07.762Z,1504983427.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2017-09-09T18:57:07.853Z,1504983427.853 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2017-09-09T18:57:08.057Z,1504983428.057 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2017-09-09T18:57:08.139Z,1504983428.139 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2017-09-09T18:57:08.142Z,1504983428.142 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-09-09T18:57:08.310Z,1504983428.310 [SBIT](DEBUG): Construct Startup Built In Test. 2017-09-09T18:57:08.346Z,1504983428.346 [SBIT] Loaded 2017-09-09T18:57:08.347Z,1504983428.347 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-09-09T18:57:08.348Z,1504983428.348 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-09-09T18:57:08.383Z,1504983428.383 [IBIT] Loaded 2017-09-09T18:57:08.383Z,1504983428.383 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-09-09T18:57:08.388Z,1504983428.388 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-09-09T18:57:08.585Z,1504983428.585 [CBIT] Loaded 2017-09-09T18:57:08.585Z,1504983428.585 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-09-09T18:57:08.586Z,1504983428.586 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-09-09T18:57:08.587Z,1504983428.587 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-09-09T18:57:08.689Z,1504983428.689 [VerticalControl](DEBUG): Construct VerticalControl. 2017-09-09T18:57:08.810Z,1504983428.810 [VerticalControl] Loaded 2017-09-09T18:57:08.810Z,1504983428.810 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-09-09T18:57:08.811Z,1504983428.811 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-09-09T18:57:08.890Z,1504983428.890 [HorizontalControl] Loaded 2017-09-09T18:57:08.890Z,1504983428.890 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-09-09T18:57:08.891Z,1504983428.891 [SpeedControl](DEBUG): Construct SpeedControl. 2017-09-09T18:57:08.898Z,1504983428.898 [SpeedControl] Loaded 2017-09-09T18:57:08.898Z,1504983428.898 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-09-09T18:57:08.899Z,1504983428.899 [LoopControl](DEBUG): Construct LoopControl. 2017-09-09T18:57:08.900Z,1504983428.900 [LoopControl] Loaded 2017-09-09T18:57:08.900Z,1504983428.900 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-09-09T18:57:08.901Z,1504983428.901 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-09-09T18:57:08.901Z,1504983428.901 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-09-09T18:57:08.944Z,1504983428.944 [DepthRateCalculator] Loaded 2017-09-09T18:57:08.944Z,1504983428.944 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-09-09T18:57:08.950Z,1504983428.950 [PitchRateCalculator] Loaded 2017-09-09T18:57:08.951Z,1504983428.951 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-09-09T18:57:08.970Z,1504983428.970 [SpeedCalculator] Loaded 2017-09-09T18:57:08.970Z,1504983428.970 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-09-09T18:57:08.996Z,1504983428.996 [TempGradientCalculator] Loaded 2017-09-09T18:57:08.997Z,1504983428.997 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-09-09T18:57:09.015Z,1504983429.015 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-09-09T18:57:09.016Z,1504983429.016 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-09-09T18:57:09.022Z,1504983429.022 [YawRateCalculator] Loaded 2017-09-09T18:57:09.022Z,1504983429.022 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-09-09T18:57:09.023Z,1504983429.023 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-09-09T18:57:09.024Z,1504983429.024 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-09-09T18:57:09.162Z,1504983429.162 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-09-09T18:57:09.162Z,1504983429.162 [StratificationFrontDetector](DEBUG): (re)initializing 2017-09-09T18:57:09.162Z,1504983429.162 [StratificationFrontDetector] Loaded 2017-09-09T18:57:09.163Z,1504983429.163 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-09-09T18:57:09.164Z,1504983429.164 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-09-09T18:57:09.164Z,1504983429.164 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-09-09T18:57:09.457Z,1504983429.457 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-09-09T18:57:09.458Z,1504983429.458 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-09-09T18:57:09.595Z,1504983429.595 [DeadReckonUsingMultipleVelocitySources] Loaded 2017-09-09T18:57:09.596Z,1504983429.596 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2017-09-09T18:57:09.664Z,1504983429.664 [DeadReckonUsingSpeedCalculator] Loaded 2017-09-09T18:57:09.665Z,1504983429.665 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-09-09T18:57:09.686Z,1504983429.686 [NavChart] Loaded 2017-09-09T18:57:09.686Z,1504983429.686 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-09-09T18:57:09.692Z,1504983429.692 [UniversalFixResidualReporter] Loaded 2017-09-09T18:57:09.692Z,1504983429.692 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-09-09T18:57:09.693Z,1504983429.693 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-09-09T18:57:09.693Z,1504983429.693 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-09-09T18:57:09.723Z,1504983429.723 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-09-09T18:57:09.724Z,1504983429.724 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-09-09T18:57:09.941Z,1504983429.941 [Aanderaa_O2] Loaded 2017-09-09T18:57:09.941Z,1504983429.941 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-09-09T18:57:10.047Z,1504983430.047 [CTD_NeilBrown] Loaded 2017-09-09T18:57:10.047Z,1504983430.047 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2017-09-09T18:57:10.049Z,1504983430.049 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408154E0 2017-09-09T18:57:10.049Z,1504983430.049 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 855 2017-09-09T18:57:10.093Z,1504983430.093 [CTD_Seabird] Loaded 2017-09-09T18:57:10.093Z,1504983430.093 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2017-09-09T18:57:10.095Z,1504983430.095 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408454E0 2017-09-09T18:57:10.095Z,1504983430.095 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 856 2017-09-09T18:57:10.114Z,1504983430.114 [PAR_Licor] Loaded 2017-09-09T18:57:10.114Z,1504983430.114 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-09-09T18:57:10.172Z,1504983430.172 [WetLabsBB2FL] Loaded 2017-09-09T18:57:10.173Z,1504983430.173 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2017-09-09T18:57:10.174Z,1504983430.174 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408754E0 2017-09-09T18:57:10.174Z,1504983430.174 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 857 2017-09-09T18:57:10.175Z,1504983430.175 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-09-09T18:57:10.175Z,1504983430.175 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-09-09T18:57:10.823Z,1504983430.823 [DataOverHttps] Loaded 2017-09-09T18:57:10.823Z,1504983430.823 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-09-09T18:57:10.840Z,1504983430.840 [Depth_Keller] Loaded 2017-09-09T18:57:10.841Z,1504983430.841 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-09-09T18:57:10.847Z,1504983430.847 [DropWeight] Loaded 2017-09-09T18:57:10.847Z,1504983430.847 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-09-09T18:57:10.960Z,1504983430.960 [NAL9602] Loaded 2017-09-09T18:57:10.960Z,1504983430.960 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-09-09T18:57:10.972Z,1504983430.972 [Onboard] Loaded 2017-09-09T18:57:10.972Z,1504983430.972 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-09-09T18:57:10.981Z,1504983430.981 [Radio_Surface] Loaded 2017-09-09T18:57:10.981Z,1504983430.981 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-09-09T18:57:10.983Z,1504983430.983 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AFC4E0 2017-09-09T18:57:10.983Z,1504983430.983 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 858 2017-09-09T18:57:11.158Z,1504983431.158 [DAT] Loaded 2017-09-09T18:57:11.159Z,1504983431.159 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2017-09-09T18:57:11.361Z,1504983431.361 [PNI_TCM] Loaded 2017-09-09T18:57:11.362Z,1504983431.362 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-09-09T18:57:11.738Z,1504983431.738 [Rowe_600LCM] Loaded 2017-09-09T18:57:11.739Z,1504983431.739 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2017-09-09T18:57:11.740Z,1504983431.740 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40B2C4E0 2017-09-09T18:57:11.740Z,1504983431.740 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 859 2017-09-09T18:57:14.206Z,1504983434.206 [BPC1] Loaded 2017-09-09T18:57:14.206Z,1504983434.206 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-09-09T18:57:14.207Z,1504983434.207 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-09-09T18:57:14.208Z,1504983434.208 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-09-09T18:57:14.500Z,1504983434.500 [BuoyancyServo] Loaded 2017-09-09T18:57:14.500Z,1504983434.500 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-09-09T18:57:14.516Z,1504983434.516 [ElevatorServo] Loaded 2017-09-09T18:57:14.516Z,1504983434.516 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-09-09T18:57:14.530Z,1504983434.530 [MassServo] Loaded 2017-09-09T18:57:14.531Z,1504983434.531 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-09-09T18:57:14.546Z,1504983434.546 [RudderServo] Loaded 2017-09-09T18:57:14.546Z,1504983434.546 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-09-09T18:57:14.560Z,1504983434.560 [ThrusterServo] Loaded 2017-09-09T18:57:14.561Z,1504983434.561 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-09-09T18:57:14.561Z,1504983434.561 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-09-09T18:57:14.562Z,1504983434.562 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-09-09T18:57:14.753Z,1504983434.753 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-09-09T18:57:14.753Z,1504983434.753 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-09-09T18:57:14.800Z,1504983434.800 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-09-09T18:57:14.805Z,1504983434.805 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-09-09T18:57:14.806Z,1504983434.806 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-09-09T18:57:14.817Z,1504983434.817 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-09-09T18:57:14.818Z,1504983434.818 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C004E0 2017-09-09T18:57:14.819Z,1504983434.819 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 861 2017-09-09T18:57:14.825Z,1504983434.825 [Supervisor](INFO): Main Thread ID is 765 2017-09-09T18:57:14.825Z,1504983434.825 [Supervisor](DEBUG): Running supervisor. 2017-09-09T18:57:14.826Z,1504983434.826 [CommandLine ThreadHandler](INFO): Handler Thread ID is 862 2017-09-09T18:57:14.829Z,1504983434.829 [controlThread ThreadHandler](INFO): Handler Thread ID is 863 2017-09-09T18:57:14.830Z,1504983434.830 [controlThread](DEBUG): Initializing ControlThread 2017-09-09T18:57:14.831Z,1504983434.831 [SBIT](INFO): Initialize SBIT Component. 2017-09-09T18:57:14.831Z,1504983434.831 [SBIT](IMPORTANT): git: 2017-08-02-81-g2dedf71 2017-09-09T18:57:14.831Z,1504983434.831 [SBIT](INFO): git hash: 2dedf719d304b5c3f7e3acd061a0c8109ea4feed 2017-09-09T18:57:14.834Z,1504983434.834 [SBIT](INFO): Kernel Reporting Different Release From Configuration. Kernel Expected: 2.6.27.8 Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty 2017-09-09T18:57:14.834Z,1504983434.834 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016 2017-09-09T18:57:14.835Z,1504983434.835 [SBIT](INFO): Beginning SBIT in 23.000000 seconds. 2017-09-09T18:57:14.836Z,1504983434.836 [IBIT](INFO): Initialize IBIT Component. 2017-09-09T18:57:14.837Z,1504983434.837 [CBIT](DEBUG): Initialize CBIT Component. 2017-09-09T18:57:14.837Z,1504983434.837 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2017-09-09T18:57:14.837Z,1504983434.837 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2017-09-09T18:57:14.838Z,1504983434.838 [logger ThreadHandler](INFO): Handler Thread ID is 864 2017-09-09T18:57:14.865Z,1504983434.865 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 865 2017-09-09T18:57:14.866Z,1504983434.866 [CTD_NeilBrown](INFO): Powering down 2017-09-09T18:57:14.895Z,1504983434.895 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 866 2017-09-09T18:57:14.896Z,1504983434.896 [CTD_Seabird](INFO): Initializing 2017-09-09T18:57:14.939Z,1504983434.939 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-09-09T18:57:14.942Z,1504983434.942 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-09-09T18:57:14.943Z,1504983434.943 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-09-09T18:57:14.943Z,1504983434.943 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-09-09T18:57:14.944Z,1504983434.944 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-09-09T18:57:14.944Z,1504983434.944 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-09-09T18:57:14.945Z,1504983434.945 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-09-09T18:57:14.945Z,1504983434.945 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-09-09T18:57:14.946Z,1504983434.946 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-09-09T18:57:14.947Z,1504983434.947 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-09-09T18:57:14.948Z,1504983434.948 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-09-09T18:57:14.949Z,1504983434.949 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-09-09T18:57:14.949Z,1504983434.949 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-09-09T18:57:14.950Z,1504983434.950 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-09-09T18:57:14.951Z,1504983434.951 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-09-09T18:57:14.951Z,1504983434.951 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-09-09T18:57:14.952Z,1504983434.952 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-09-09T18:57:14.952Z,1504983434.952 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-09-09T18:57:14.961Z,1504983434.961 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 868 2017-09-09T18:57:14.963Z,1504983434.963 [WetLabsBB2FL](INFO): Powering down 2017-09-09T18:57:15.002Z,1504983435.002 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-09-09T18:57:15.015Z,1504983435.015 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 869 2017-09-09T18:57:15.049Z,1504983435.049 [Radio_Surface](INFO): Powering up 2017-09-09T18:57:15.049Z,1504983435.049 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-09T18:57:15.037Z,1504983435.037 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 870 2017-09-09T18:57:15.053Z,1504983435.053 [Rowe_600LCM](INFO): Initializing 2017-09-09T18:57:15.054Z,1504983435.054 [Rowe_600LCM](INFO): Checking LCM 2017-09-09T18:57:15.055Z,1504983435.055 [Rowe_600LCM](INFO): LCM OK 2017-09-09T18:57:15.055Z,1504983435.055 [Rowe_600LCM](INFO): Powering up 2017-09-09T18:57:15.073Z,1504983435.073 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 871 2017-09-09T18:57:15.082Z,1504983435.082 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-09-09T18:57:15.082Z,1504983435.082 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-09-09T18:57:15.082Z,1504983435.082 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-09-09T18:57:15.082Z,1504983435.082 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-09-09T18:57:15.083Z,1504983435.083 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-09-09T18:57:15.083Z,1504983435.083 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-09-09T18:57:15.083Z,1504983435.083 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-09-09T18:57:15.083Z,1504983435.083 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-09-09T18:57:15.083Z,1504983435.083 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-09-09T18:57:15.084Z,1504983435.084 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-09-09T18:57:15.084Z,1504983435.084 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-09-09T18:57:15.084Z,1504983435.084 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-09-09T18:57:15.084Z,1504983435.084 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-09-09T18:57:15.085Z,1504983435.085 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-09-09T18:57:15.085Z,1504983435.085 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-09-09T18:57:15.085Z,1504983435.085 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-09-09T18:57:15.122Z,1504983435.122 [MissionManager](DEBUG): 2017-09-09T18:57:15.123Z,1504983435.123 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-09-09T18:57:15.214Z,1504983435.214 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-09-09T18:57:15.215Z,1504983435.215 [Default:A.Wait](DEBUG): Construct Wait. 2017-09-09T18:57:15.218Z,1504983435.218 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-09T18:57:15.239Z,1504983435.239 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2017-09-09T18:57:15.239Z,1504983435.239 [CTD_Seabird](INFO): Powering down 2017-09-09T18:57:15.314Z,1504983435.314 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-09-09T18:57:15.317Z,1504983435.317 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-09-09T18:57:15.341Z,1504983435.341 [Default:E.Execute](DEBUG): Construct Execute. 2017-09-09T18:57:15.345Z,1504983435.345 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2017-09-09T18:57:15.370Z,1504983435.370 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2017-09-09T18:57:15.542Z,1504983435.542 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-09-09T18:57:15.567Z,1504983435.567 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2017-09-09T18:57:15.645Z,1504983435.645 [DAT](INFO): Powering up 2017-09-09T18:57:15.645Z,1504983435.645 [DAT](DEBUG): Initializing DAT. 2017-09-09T18:57:15.867Z,1504983435.867 [DepthRateCalculator](ERROR): Depth measurement is not active 2017-09-09T18:57:16.003Z,1504983436.003 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:16.233Z,1504983436.233 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:16.388Z,1504983436.388 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-09-09T18:57:16.395Z,1504983436.395 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-09-09T18:57:16.419Z,1504983436.419 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-09-09T18:57:16.427Z,1504983436.427 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-09-09T18:57:16.450Z,1504983436.450 [MassServo](DEBUG): Initializing EZServoServo. 2017-09-09T18:57:16.451Z,1504983436.451 [MassServo](DEBUG): Initializing MassServo. 2017-09-09T18:57:16.490Z,1504983436.490 [RudderServo](DEBUG): Initializing EZServoServo. 2017-09-09T18:57:16.491Z,1504983436.491 [RudderServo](DEBUG): Initializing RudderServo. 2017-09-09T18:57:16.514Z,1504983436.514 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-09-09T18:57:16.520Z,1504983436.520 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-09-09T18:57:16.576Z,1504983436.576 [CommandLine](FAULT): Scheduling is paused 2017-09-09T18:57:16.577Z,1504983436.577 [CBIT](INFO): Critical error at 20170909T185714 2017-09-09T18:57:16.577Z,1504983436.577 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2017-09-09T18:57:16.834Z,1504983436.834 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2017-09-09T18:57:16.834Z,1504983436.834 [DropWeight] Hardware Fault, FailCount= 1 2017-09-09T18:57:16.834Z,1504983436.834 [DropWeight](ERROR): Hardware Fault 2017-09-09T18:57:16.836Z,1504983436.836 [NAL9602](INFO): Powering up NAL9602 2017-09-09T18:57:16.924Z,1504983436.924 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:16.926Z,1504983436.926 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:17.276Z,1504983437.276 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2017-09-09T18:57:17.276Z,1504983437.276 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2017-09-09T18:57:17.276Z,1504983437.276 [BuoyancyServo] Communications Fault, FailCount= 1 2017-09-09T18:57:17.276Z,1504983437.276 [BuoyancyServo](ERROR): Communications Fault 2017-09-09T18:57:17.559Z,1504983437.559 [CBIT](INFO): Critical error at 20170909T185716 2017-09-09T18:57:17.562Z,1504983437.562 [CBIT](ERROR): Hardware Fault in component: DropWeight 2017-09-09T18:57:17.562Z,1504983437.562 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2017-09-09T18:57:17.563Z,1504983437.563 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2017-09-09T18:57:17.654Z,1504983437.654 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:17.655Z,1504983437.655 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:17.679Z,1504983437.679 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2017-09-09T18:57:17.679Z,1504983437.679 [BuoyancyServo](INFO): Powering down 2017-09-09T18:57:17.777Z,1504983437.777 [CBIT](INFO): Critical error at 20170909T185717 2017-09-09T18:57:18.055Z,1504983438.055 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:18.056Z,1504983438.056 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:18.490Z,1504983438.490 [Aanderaa_O2](INFO): Powering down 2017-09-09T18:57:18.700Z,1504983438.700 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:18.701Z,1504983438.701 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:18.843Z,1504983438.843 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:18.845Z,1504983438.845 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:19.229Z,1504983439.229 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:19.231Z,1504983439.231 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-09T18:57:19.369Z,1504983439.369 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-09-09T18:57:19.459Z,1504983439.459 [Rowe_600LCM](INFO): Started Rowe LCM