2017-09-12T17:47:00.796Z,1505238420.796 [Supervisor](DEBUG): Initializing supervisor. 2017-09-12T17:47:00.800Z,1505238420.800 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2017-09-12T17:47:00.801Z,1505238420.801 [SyncHandler](INFO): Protected caller Thread ID is 769 2017-09-12T17:47:00.801Z,1505238420.801 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-09-12T17:47:00.806Z,1505238420.806 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2017-09-12T17:47:00.807Z,1505238420.807 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 770 2017-09-12T17:47:00.810Z,1505238420.810 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-09-12T17:47:00.825Z,1505238420.825 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-09-12T17:47:00.826Z,1505238420.826 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2017-09-12T17:47:00.827Z,1505238420.827 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 771 2017-09-12T17:47:00.828Z,1505238420.828 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-09-12T17:47:00.830Z,1505238420.830 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2017-09-12T17:47:00.831Z,1505238420.831 [logger ThreadHandler](INFO): Protected caller Thread ID is 772 2017-09-12T17:47:00.833Z,1505238420.833 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-09-12T17:47:00.834Z,1505238420.834 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-09-12T17:47:00.837Z,1505238420.837 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-09-12T17:47:01.063Z,1505238421.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-09-12T17:47:01.064Z,1505238421.064 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-09-12T17:47:01.219Z,1505238421.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-09-12T17:47:01.220Z,1505238421.220 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-09-12T17:47:01.649Z,1505238421.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-09-12T17:47:01.650Z,1505238421.650 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-09-12T17:47:01.815Z,1505238421.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-09-12T17:47:01.816Z,1505238421.816 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-09-12T17:47:01.913Z,1505238421.913 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-09-12T17:47:02.159Z,1505238422.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-09-12T17:47:02.162Z,1505238422.162 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-09-12T17:47:02.278Z,1505238422.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-09-12T17:47:02.279Z,1505238422.279 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-09-12T17:47:02.613Z,1505238422.613 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-09-12T17:47:02.614Z,1505238422.614 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-09-12T17:47:03.052Z,1505238423.052 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-09-12T17:47:03.052Z,1505238423.052 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-09-12T17:47:03.416Z,1505238423.416 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-09-12T17:47:03.417Z,1505238423.417 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-09-12T17:47:15.170Z,1505238435.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-09-12T17:47:16.102Z,1505238436.102 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-09-12T17:47:16.336Z,1505238436.336 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-09-12T17:47:16.336Z,1505238436.336 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-09-12T17:47:16.445Z,1505238436.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-09-12T17:47:16.445Z,1505238436.445 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-09-12T17:47:17.003Z,1505238437.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-09-12T17:47:17.003Z,1505238437.003 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-09-12T17:47:17.121Z,1505238437.121 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-09-12T17:47:17.123Z,1505238437.123 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2017-09-12T17:47:17.126Z,1505238437.126 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2017-09-12T17:47:17.427Z,1505238437.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-09-12T17:47:17.428Z,1505238437.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2017-09-12T17:47:17.537Z,1505238437.537 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2017-09-12T17:47:17.635Z,1505238437.635 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2017-09-12T17:47:17.747Z,1505238437.747 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2017-09-12T17:47:17.840Z,1505238437.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2017-09-12T17:47:17.980Z,1505238437.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2017-09-12T17:47:18.152Z,1505238438.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2017-09-12T17:47:18.255Z,1505238438.255 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2017-09-12T17:47:18.354Z,1505238438.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2017-09-12T17:47:18.445Z,1505238438.445 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2017-09-12T17:47:18.646Z,1505238438.646 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2017-09-12T17:47:18.729Z,1505238438.729 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2017-09-12T17:47:18.729Z,1505238438.729 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2017-09-12T17:47:18.741Z,1505238438.741 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-09-12T17:47:18.905Z,1505238438.905 [SBIT](DEBUG): Construct Startup Built In Test. 2017-09-12T17:47:18.942Z,1505238438.942 [SBIT] Loaded 2017-09-12T17:47:18.942Z,1505238438.942 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-09-12T17:47:18.943Z,1505238438.943 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-09-12T17:47:18.978Z,1505238438.978 [IBIT] Loaded 2017-09-12T17:47:18.978Z,1505238438.978 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-09-12T17:47:18.983Z,1505238438.983 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-09-12T17:47:19.178Z,1505238439.178 [CBIT] Loaded 2017-09-12T17:47:19.179Z,1505238439.179 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-09-12T17:47:19.179Z,1505238439.179 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-09-12T17:47:19.180Z,1505238439.180 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-09-12T17:47:19.278Z,1505238439.278 [VerticalControl](DEBUG): Construct VerticalControl. 2017-09-12T17:47:19.398Z,1505238439.398 [VerticalControl] Loaded 2017-09-12T17:47:19.398Z,1505238439.398 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-09-12T17:47:19.399Z,1505238439.399 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-09-12T17:47:19.477Z,1505238439.477 [HorizontalControl] Loaded 2017-09-12T17:47:19.478Z,1505238439.478 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-09-12T17:47:19.478Z,1505238439.478 [SpeedControl](DEBUG): Construct SpeedControl. 2017-09-12T17:47:19.485Z,1505238439.485 [SpeedControl] Loaded 2017-09-12T17:47:19.486Z,1505238439.486 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-09-12T17:47:19.487Z,1505238439.487 [LoopControl](DEBUG): Construct LoopControl. 2017-09-12T17:47:19.487Z,1505238439.487 [LoopControl] Loaded 2017-09-12T17:47:19.488Z,1505238439.488 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-09-12T17:47:19.488Z,1505238439.488 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-09-12T17:47:19.489Z,1505238439.489 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-09-12T17:47:19.531Z,1505238439.531 [DepthRateCalculator] Loaded 2017-09-12T17:47:19.531Z,1505238439.531 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-09-12T17:47:19.538Z,1505238439.538 [PitchRateCalculator] Loaded 2017-09-12T17:47:19.538Z,1505238439.538 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-09-12T17:47:19.590Z,1505238439.590 [SpeedCalculator] Loaded 2017-09-12T17:47:19.590Z,1505238439.590 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-09-12T17:47:19.631Z,1505238439.631 [TempGradientCalculator] Loaded 2017-09-12T17:47:19.631Z,1505238439.631 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-09-12T17:47:19.650Z,1505238439.650 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-09-12T17:47:19.650Z,1505238439.650 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-09-12T17:47:19.657Z,1505238439.657 [YawRateCalculator] Loaded 2017-09-12T17:47:19.657Z,1505238439.657 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-09-12T17:47:19.657Z,1505238439.657 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-09-12T17:47:19.658Z,1505238439.658 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-09-12T17:47:19.797Z,1505238439.797 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-09-12T17:47:19.797Z,1505238439.797 [StratificationFrontDetector](DEBUG): (re)initializing 2017-09-12T17:47:19.797Z,1505238439.797 [StratificationFrontDetector] Loaded 2017-09-12T17:47:19.797Z,1505238439.797 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-09-12T17:47:19.798Z,1505238439.798 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-09-12T17:47:19.799Z,1505238439.799 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-09-12T17:47:20.086Z,1505238440.086 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-09-12T17:47:20.086Z,1505238440.086 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-09-12T17:47:21.695Z,1505238441.695 [DeadReckonUsingMultipleVelocitySources] Loaded 2017-09-12T17:47:21.696Z,1505238441.696 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2017-09-12T17:47:21.764Z,1505238441.764 [DeadReckonUsingSpeedCalculator] Loaded 2017-09-12T17:47:21.765Z,1505238441.765 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-09-12T17:47:21.785Z,1505238441.785 [NavChart] Loaded 2017-09-12T17:47:21.786Z,1505238441.786 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-09-12T17:47:21.791Z,1505238441.791 [UniversalFixResidualReporter] Loaded 2017-09-12T17:47:21.792Z,1505238441.792 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-09-12T17:47:21.792Z,1505238441.792 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-09-12T17:47:21.793Z,1505238441.793 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-09-12T17:47:28.708Z,1505238448.708 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-09-12T17:47:28.709Z,1505238448.709 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-09-12T17:47:29.135Z,1505238449.135 [Aanderaa_O2] Loaded 2017-09-12T17:47:29.135Z,1505238449.135 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-09-12T17:47:29.242Z,1505238449.242 [CTD_NeilBrown] Loaded 2017-09-12T17:47:29.242Z,1505238449.242 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2017-09-12T17:47:29.243Z,1505238449.243 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408134E0 2017-09-12T17:47:29.244Z,1505238449.244 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 856 2017-09-12T17:47:29.262Z,1505238449.262 [PAR_Licor] Loaded 2017-09-12T17:47:29.263Z,1505238449.263 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-09-12T17:47:29.321Z,1505238449.321 [WetLabsBB2FL] Loaded 2017-09-12T17:47:29.322Z,1505238449.322 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2017-09-12T17:47:29.323Z,1505238449.323 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408434E0 2017-09-12T17:47:29.323Z,1505238449.323 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 857 2017-09-12T17:47:29.324Z,1505238449.324 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-09-12T17:47:29.324Z,1505238449.324 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-09-12T17:47:29.969Z,1505238449.969 [DataOverHttps] Loaded 2017-09-12T17:47:29.969Z,1505238449.969 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-09-12T17:47:29.987Z,1505238449.987 [Depth_Keller] Loaded 2017-09-12T17:47:29.987Z,1505238449.987 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-09-12T17:47:29.993Z,1505238449.993 [DropWeight] Loaded 2017-09-12T17:47:29.994Z,1505238449.994 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-09-12T17:47:30.106Z,1505238450.106 [NAL9602] Loaded 2017-09-12T17:47:30.106Z,1505238450.106 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-09-12T17:47:30.118Z,1505238450.118 [Onboard] Loaded 2017-09-12T17:47:30.118Z,1505238450.118 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-09-12T17:47:30.127Z,1505238450.127 [Radio_Surface] Loaded 2017-09-12T17:47:30.127Z,1505238450.127 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-09-12T17:47:30.129Z,1505238450.129 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AC74E0 2017-09-12T17:47:30.129Z,1505238450.129 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 858 2017-09-12T17:47:30.303Z,1505238450.303 [DAT] Loaded 2017-09-12T17:47:30.303Z,1505238450.303 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2017-09-12T17:47:30.507Z,1505238450.507 [PNI_TCM] Loaded 2017-09-12T17:47:30.507Z,1505238450.507 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-09-12T17:47:32.950Z,1505238452.950 [BPC1] Loaded 2017-09-12T17:47:32.950Z,1505238452.950 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-09-12T17:47:32.950Z,1505238452.950 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-09-12T17:47:32.951Z,1505238452.951 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-09-12T17:47:33.082Z,1505238453.082 [BuoyancyServo] Loaded 2017-09-12T17:47:33.082Z,1505238453.082 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-09-12T17:47:33.098Z,1505238453.098 [ElevatorServo] Loaded 2017-09-12T17:47:33.098Z,1505238453.098 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-09-12T17:47:33.113Z,1505238453.113 [MassServo] Loaded 2017-09-12T17:47:33.113Z,1505238453.113 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-09-12T17:47:33.128Z,1505238453.128 [RudderServo] Loaded 2017-09-12T17:47:33.128Z,1505238453.128 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-09-12T17:47:33.143Z,1505238453.143 [ThrusterServo] Loaded 2017-09-12T17:47:33.143Z,1505238453.143 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-09-12T17:47:33.143Z,1505238453.143 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-09-12T17:47:33.144Z,1505238453.144 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-09-12T17:47:33.283Z,1505238453.283 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-09-12T17:47:33.284Z,1505238453.284 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-09-12T17:47:33.330Z,1505238453.330 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-09-12T17:47:33.335Z,1505238453.335 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-09-12T17:47:33.336Z,1505238453.336 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-09-12T17:47:33.347Z,1505238453.347 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-09-12T17:47:33.348Z,1505238453.348 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B9B4E0 2017-09-12T17:47:33.348Z,1505238453.348 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 859 2017-09-12T17:47:33.355Z,1505238453.355 [Supervisor](INFO): Main Thread ID is 765 2017-09-12T17:47:33.355Z,1505238453.355 [Supervisor](DEBUG): Running supervisor. 2017-09-12T17:47:33.356Z,1505238453.356 [CommandLine ThreadHandler](INFO): Handler Thread ID is 860 2017-09-12T17:47:33.359Z,1505238453.359 [controlThread ThreadHandler](INFO): Handler Thread ID is 861 2017-09-12T17:47:33.359Z,1505238453.359 [controlThread](DEBUG): Initializing ControlThread 2017-09-12T17:47:33.360Z,1505238453.360 [SBIT](INFO): Initialize SBIT Component. 2017-09-12T17:47:33.361Z,1505238453.361 [SBIT](IMPORTANT): git: 2017-08-02-103-g54acef0 2017-09-12T17:47:33.361Z,1505238453.361 [SBIT](INFO): git hash: 54acef0e8867e4ebce852e89742b80c54cea63d9 2017-09-12T17:47:33.363Z,1505238453.363 [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-12T17:47:33.364Z,1505238453.364 [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-12T17:47:33.365Z,1505238453.365 [SBIT](INFO): Beginning SBIT in 71.000000 seconds. 2017-09-12T17:47:33.366Z,1505238453.366 [IBIT](INFO): Initialize IBIT Component. 2017-09-12T17:47:33.366Z,1505238453.366 [CBIT](DEBUG): Initialize CBIT Component. 2017-09-12T17:47:33.367Z,1505238453.367 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2017-09-12T17:47:33.368Z,1505238453.368 [logger ThreadHandler](INFO): Handler Thread ID is 862 2017-09-12T17:47:33.394Z,1505238453.394 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 863 2017-09-12T17:47:33.395Z,1505238453.395 [CTD_NeilBrown](INFO): Powering down 2017-09-12T17:47:33.418Z,1505238453.418 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 864 2017-09-12T17:47:33.420Z,1505238453.420 [WetLabsBB2FL](INFO): Powering down 2017-09-12T17:47:33.450Z,1505238453.450 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-09-12T17:47:33.452Z,1505238453.452 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-09-12T17:47:33.453Z,1505238453.453 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-09-12T17:47:33.453Z,1505238453.453 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-09-12T17:47:33.454Z,1505238453.454 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-09-12T17:47:33.454Z,1505238453.454 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-09-12T17:47:33.455Z,1505238453.455 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-09-12T17:47:33.455Z,1505238453.455 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-09-12T17:47:33.456Z,1505238453.456 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-09-12T17:47:33.456Z,1505238453.456 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-09-12T17:47:33.457Z,1505238453.457 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-09-12T17:47:33.458Z,1505238453.458 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-09-12T17:47:33.459Z,1505238453.459 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-09-12T17:47:33.459Z,1505238453.459 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-09-12T17:47:33.460Z,1505238453.460 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-09-12T17:47:33.460Z,1505238453.460 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-09-12T17:47:33.460Z,1505238453.460 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-09-12T17:47:33.461Z,1505238453.461 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-09-12T17:47:33.484Z,1505238453.484 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-09-12T17:47:33.497Z,1505238453.497 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 865 2017-09-12T17:47:33.506Z,1505238453.506 [Radio_Surface](INFO): Powering up 2017-09-12T17:47:33.507Z,1505238453.507 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 866 2017-09-12T17:47:33.520Z,1505238453.520 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-09-12T17:47:33.521Z,1505238453.521 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-09-12T17:47:33.521Z,1505238453.521 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-09-12T17:47:33.521Z,1505238453.521 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-09-12T17:47:33.521Z,1505238453.521 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-09-12T17:47:33.522Z,1505238453.522 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-09-12T17:47:33.522Z,1505238453.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-09-12T17:47:33.522Z,1505238453.522 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-09-12T17:47:33.522Z,1505238453.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-09-12T17:47:33.523Z,1505238453.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-09-12T17:47:33.523Z,1505238453.523 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-09-12T17:47:33.523Z,1505238453.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-09-12T17:47:33.523Z,1505238453.523 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-09-12T17:47:33.523Z,1505238453.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-09-12T17:47:33.524Z,1505238453.524 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-09-12T17:47:33.524Z,1505238453.524 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-09-12T17:47:33.597Z,1505238453.597 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-12T17:47:33.647Z,1505238453.647 [MissionManager](DEBUG): 2017-09-12T17:47:33.648Z,1505238453.648 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-09-12T17:47:33.712Z,1505238453.712 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-09-12T17:47:33.714Z,1505238453.714 [Default:A.Wait](DEBUG): Construct Wait. 2017-09-12T17:47:33.732Z,1505238453.732 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-12T17:47:33.765Z,1505238453.765 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-09-12T17:47:33.784Z,1505238453.784 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-09-12T17:47:33.802Z,1505238453.802 [Default:E.Execute](DEBUG): Construct Execute. 2017-09-12T17:47:33.830Z,1505238453.830 [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-12T17:47:33.836Z,1505238453.836 [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-12T17:47:33.999Z,1505238453.999 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-09-12T17:47:34.032Z,1505238454.032 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2017-09-12T17:47:34.118Z,1505238454.118 [DAT](INFO): Powering up 2017-09-12T17:47:34.118Z,1505238454.118 [DAT](DEBUG): Initializing DAT. 2017-09-12T17:47:34.332Z,1505238454.332 [DepthRateCalculator](ERROR): Depth measurement is not active 2017-09-12T17:47:34.430Z,1505238454.430 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:34.688Z,1505238454.688 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:34.826Z,1505238454.826 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-09-12T17:47:34.832Z,1505238454.832 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-09-12T17:47:34.857Z,1505238454.857 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-09-12T17:47:34.864Z,1505238454.864 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-09-12T17:47:34.879Z,1505238454.879 [MassServo](DEBUG): Initializing EZServoServo. 2017-09-12T17:47:34.888Z,1505238454.888 [MassServo](DEBUG): Initializing MassServo. 2017-09-12T17:47:34.913Z,1505238454.913 [RudderServo](DEBUG): Initializing EZServoServo. 2017-09-12T17:47:34.920Z,1505238454.920 [RudderServo](DEBUG): Initializing RudderServo. 2017-09-12T17:47:34.927Z,1505238454.927 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-09-12T17:47:34.933Z,1505238454.933 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-09-12T17:47:35.203Z,1505238455.203 [NAL9602](INFO): Powering up NAL9602 2017-09-12T17:47:35.305Z,1505238455.305 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:35.313Z,1505238455.313 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:35.518Z,1505238455.518 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:35.520Z,1505238455.520 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:36.023Z,1505238456.023 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:36.024Z,1505238456.024 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:36.436Z,1505238456.436 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:36.437Z,1505238456.437 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:36.828Z,1505238456.828 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:36.829Z,1505238456.829 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:37.280Z,1505238457.280 [Aanderaa_O2](INFO): Powering down 2017-09-12T17:47:37.421Z,1505238457.421 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:37.422Z,1505238457.422 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:37.648Z,1505238457.648 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:37.650Z,1505238457.650 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T17:47:46.160Z,1505238466.160 [NAL9602](INFO): NAL9602 initialized 2017-09-12T17:47:46.932Z,1505238466.932 [CommandLine](IMPORTANT): got command failComponent 2017-09-12T17:47:46.932Z,1505238466.932 [CommandLine](IMPORTANT): Failed components: 2017-09-12T17:47:46.933Z,1505238466.933 [CommandLine](IMPORTANT): No failed Components. 2017-09-12T17:48:24.564Z,1505238504.564 [DAT](DEBUG): Teledyne Benthos ATM-900 Series MF Frequency Band Directional Acoustic Transponder version 8.3.1 Jan 3 2000 03:41:30 Warning battery low CONNECT 2017-09-12T17:48:24.564Z,1505238504.564 [DAT](INFO): Got CONNECT 2017-09-12T17:48:24.564Z,1505238504.564 [DAT](INFO): entering command mode 2017-09-12T17:48:24.960Z,1505238504.960 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:25.382Z,1505238505.382 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:25.756Z,1505238505.756 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:26.164Z,1505238506.164 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:26.574Z,1505238506.574 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:26.950Z,1505238506.950 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:27.346Z,1505238507.346 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:27.751Z,1505238507.751 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:28.156Z,1505238508.156 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:28.547Z,1505238508.547 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:28.945Z,1505238508.945 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:29.354Z,1505238509.354 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:29.750Z,1505238509.750 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:30.166Z,1505238510.166 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:30.562Z,1505238510.562 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:30.973Z,1505238510.973 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:31.347Z,1505238511.347 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:31.745Z,1505238511.745 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:32.146Z,1505238512.146 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:32.546Z,1505238512.546 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:32.982Z,1505238512.982 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:33.343Z,1505238513.343 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:33.758Z,1505238513.758 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:34.170Z,1505238514.170 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:34.549Z,1505238514.549 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:34.957Z,1505238514.957 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:35.358Z,1505238515.358 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:35.743Z,1505238515.743 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:36.144Z,1505238516.144 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:36.544Z,1505238516.544 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:36.945Z,1505238516.945 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:37.346Z,1505238517.346 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:37.772Z,1505238517.772 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:38.161Z,1505238518.161 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:38.555Z,1505238518.555 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:38.956Z,1505238518.956 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:39.348Z,1505238519.348 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:39.746Z,1505238519.746 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:40.146Z,1505238520.146 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:40.543Z,1505238520.543 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:40.948Z,1505238520.948 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:41.352Z,1505238521.352 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:41.745Z,1505238521.745 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:42.172Z,1505238522.172 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:42.560Z,1505238522.560 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:42.951Z,1505238522.951 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:43.352Z,1505238523.352 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:43.756Z,1505238523.756 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T17:48:44.144Z,1505238524.144 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: Teledyne Benthos ATM-900 Series MF Frequency Band Directional Acoustic Transponder version 8.3.1 Jan 3 2000 03:41:30 Warning battery low CONNECT, available: 02400 bits/sec 1 of 4 user:1>œQ@ 2017-09-12T17:48:44.145Z,1505238524.145 [DAT] Communications Fault, FailCount= 1 2017-09-12T17:48:44.145Z,1505238524.145 [DAT](ERROR): Communications Fault 2017-09-12T17:48:44.293Z,1505238524.293 [CBIT](ERROR): Communications Fault in component: DAT 2017-09-12T17:48:44.557Z,1505238524.557 [DAT](INFO): Powering down 2017-09-12T17:48:45.074Z,1505238525.074 [SBIT](IMPORTANT): Beginning Startup BIT 2017-09-12T17:48:45.087Z,1505238525.087 [CBIT](IMPORTANT): Beginning ground fault scan 2017-09-12T17:48:45.503Z,1505238525.503 [CBIT](INFO): Clearing failed state for component DAT 2017-09-12T17:48:45.503Z,1505238525.503 [DAT] No Fault, FailCount= 1 2017-09-12T17:48:47.906Z,1505238527.906 [DAT](INFO): Powering up 2017-09-12T17:48:47.907Z,1505238527.907 [DAT](DEBUG): Initializing DAT. 2017-09-12T17:48:55.614Z,1505238535.614 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 4.657929 CHAN A1 (24V): 0.027461 CHAN A2 (12V): 4.697929 CHAN A3 (5V): -0.011429 CHAN B0 (3.3V): 0.000199 CHAN B1 (3.15aV): -0.000379 CHAN B2 (3.15bV): -0.000332 CHAN B3 (GND): -0.000009 OPEN: -0.000262 Full Scale Calc: 4.765 mA, -1.589 mA 2017-09-12T17:49:05.333Z,1505238545.333 [CommandLine](IMPORTANT): got command restart application 2017-09-12T17:49:06.341Z,1505238546.341 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2017-09-12T17:49:06.353Z,1505238546.353 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-12T17:49:06.354Z,1505238546.354 [CommandLine ThreadHandler](INFO): Thread cancelled. 2017-09-12T17