2016-06-29T17:10:16.703Z,1467220216.703 [Supervisor](DEBUG): Initializing supervisor. 2016-06-29T17:10:16.706Z,1467220216.706 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2016-06-29T17:10:16.707Z,1467220216.707 [SyncHandler](INFO): Protected caller Thread ID is 768 2016-06-29T17:10:16.707Z,1467220216.707 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2016-06-29T17:10:16.708Z,1467220216.708 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2016-06-29T17:10:16.709Z,1467220216.709 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 769 2016-06-29T17:10:16.711Z,1467220216.711 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2016-06-29T17:10:16.723Z,1467220216.723 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2016-06-29T17:10:16.724Z,1467220216.724 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2016-06-29T17:10:16.724Z,1467220216.724 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 770 2016-06-29T17:10:16.725Z,1467220216.725 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2016-06-29T17:10:16.726Z,1467220216.726 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2016-06-29T17:10:16.726Z,1467220216.726 [logger ThreadHandler](INFO): Protected caller Thread ID is 771 2016-06-29T17:10:16.728Z,1467220216.728 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2016-06-29T17:10:16.729Z,1467220216.729 [Supervisor](INFO): Looking for Config files in directory: Config/ 2016-06-29T17:10:16.734Z,1467220216.734 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2016-06-29T17:10:16.820Z,1467220216.820 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2016-06-29T17:10:17.132Z,1467220217.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2016-06-29T17:10:17.133Z,1467220217.133 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2016-06-29T17:10:17.255Z,1467220217.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2016-06-29T17:10:17.256Z,1467220217.256 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2016-06-29T17:10:17.452Z,1467220217.452 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2016-06-29T17:10:17.454Z,1467220217.454 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2016-06-29T17:10:17.555Z,1467220217.555 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2016-06-29T17:10:17.555Z,1467220217.556 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2016-06-29T17:10:17.730Z,1467220217.730 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2016-06-29T17:10:17.732Z,1467220217.732 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2016-06-29T17:10:18.186Z,1467220218.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2016-06-29T17:10:18.187Z,1467220218.187 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2016-06-29T17:10:18.459Z,1467220218.459 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2016-06-29T17:10:18.460Z,1467220218.460 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2016-06-29T17:10:18.546Z,1467220218.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2016-06-29T17:10:18.548Z,1467220218.548 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2016-06-29T17:10:18.678Z,1467220218.678 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2016-06-29T17:10:18.678Z,1467220218.678 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2016-06-29T17:10:18.867Z,1467220218.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2016-06-29T17:10:18.868Z,1467220218.868 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2016-06-29T17:10:19.293Z,1467220219.293 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2016-06-29T17:10:19.293Z,1467220219.293 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2016-06-29T17:10:19.761Z,1467220219.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2016-06-29T17:10:19.761Z,1467220219.761 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2016-06-29T17:10:25.209Z,1467220225.209 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2016-06-29T17:10:25.210Z,1467220225.210 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2016-06-29T17:10:25.320Z,1467220225.320 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2016-06-29T17:10:25.322Z,1467220225.322 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/ 2016-06-29T17:10:25.326Z,1467220225.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg 2016-06-29T17:10:25.424Z,1467220225.424 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Navigation.cfg 2016-06-29T17:10:25.520Z,1467220225.520 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg 2016-06-29T17:10:25.609Z,1467220225.609 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg 2016-06-29T17:10:25.709Z,1467220225.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg 2016-06-29T17:10:25.799Z,1467220225.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg 2016-06-29T17:10:25.941Z,1467220225.941 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg 2016-06-29T17:10:26.039Z,1467220226.039 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg 2016-06-29T17:10:26.201Z,1467220226.201 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg 2016-06-29T17:10:26.430Z,1467220226.430 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2016-06-29T17:10:26.431Z,1467220226.431 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg 2016-06-29T17:10:26.608Z,1467220226.608 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg 2016-06-29T17:10:26.715Z,1467220226.715 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2016-06-29T17:10:26.718Z,1467220226.718 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2016-06-29T17:10:26.760Z,1467220226.760 [DepthRateCalculator] Loaded 2016-06-29T17:10:26.760Z,1467220226.760 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2016-06-29T17:10:26.766Z,1467220226.766 [PitchRateCalculator] Loaded 2016-06-29T17:10:26.767Z,1467220226.767 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2016-06-29T17:10:26.778Z,1467220226.778 [SpeedCalculator] Loaded 2016-06-29T17:10:26.779Z,1467220226.779 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2016-06-29T17:10:26.795Z,1467220226.795 [TempGradientCalculator] Loaded 2016-06-29T17:10:26.795Z,1467220226.795 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2016-06-29T17:10:26.811Z,1467220226.811 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2016-06-29T17:10:26.812Z,1467220226.812 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2016-06-29T17:10:26.817Z,1467220226.818 [YawRateCalculator] Loaded 2016-06-29T17:10:26.818Z,1467220226.818 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2016-06-29T17:10:26.818Z,1467220226.818 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2016-06-29T17:10:26.819Z,1467220226.819 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2016-06-29T17:10:26.942Z,1467220226.942 [DeadReckonUsingMultipleVelocitySources] Loaded 2016-06-29T17:10:26.942Z,1467220226.942 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2016-06-29T17:10:26.998Z,1467220226.998 [DeadReckonUsingSpeedCalculator] Loaded 2016-06-29T17:10:26.998Z,1467220226.999 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2016-06-29T17:10:27.016Z,1467220227.016 [NavChart] Loaded 2016-06-29T17:10:27.016Z,1467220227.016 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2016-06-29T17:10:27.021Z,1467220227.020 [UniversalFixResidualReporter] Loaded 2016-06-29T17:10:27.021Z,1467220227.021 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2016-06-29T17:10:27.021Z,1467220227.021 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2016-06-29T17:10:27.022Z,1467220227.022 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2016-06-29T17:10:27.162Z,1467220227.162 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2016-06-29T17:10:27.162Z,1467220227.162 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2016-06-29T17:10:27.203Z,1467220227.203 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2016-06-29T17:10:27.204Z,1467220227.204 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2016-06-29T17:10:27.213Z,1467220227.213 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2016-06-29T17:10:27.214Z,1467220227.214 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2016-06-29T17:10:27.493Z,1467220227.493 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2016-06-29T17:10:27.493Z,1467220227.493 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2016-06-29T17:10:27.642Z,1467220227.642 [SBIT](DEBUG): Construct Startup Built In Test. 2016-06-29T17:10:27.674Z,1467220227.674 [SBIT] Loaded 2016-06-29T17:10:27.675Z,1467220227.675 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2016-06-29T17:10:27.675Z,1467220227.675 [IBIT](DEBUG): Construct Initiated Built In Test. 2016-06-29T17:10:27.704Z,1467220227.704 [IBIT] Loaded 2016-06-29T17:10:27.704Z,1467220227.704 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2016-06-29T17:10:27.708Z,1467220227.708 [CBIT](DEBUG): Construct Continuous Built In Test. 2016-06-29T17:10:27.864Z,1467220227.864 [CBIT] Loaded 2016-06-29T17:10:27.864Z,1467220227.864 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2016-06-29T17:10:27.865Z,1467220227.865 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2016-06-29T17:10:27.865Z,1467220227.865 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2016-06-29T17:10:28.489Z,1467220228.489 [DataOverHttps] Loaded 2016-06-29T17:10:28.490Z,1467220228.490 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2016-06-29T17:10:28.518Z,1467220228.518 [Depth_Keller] Loaded 2016-06-29T17:10:28.518Z,1467220228.518 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2016-06-29T17:10:28.612Z,1467220228.612 [NAL9602] Loaded 2016-06-29T17:10:28.612Z,1467220228.612 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2016-06-29T17:10:28.622Z,1467220228.622 [Onboard] Loaded 2016-06-29T17:10:28.623Z,1467220228.623 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2016-06-29T17:10:28.630Z,1467220228.630 [Radio_Surface] Loaded 2016-06-29T17:10:28.630Z,1467220228.630 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2016-06-29T17:10:28.632Z,1467220228.632 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409234E0 2016-06-29T17:10:28.632Z,1467220228.632 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 851 2016-06-29T17:10:28.828Z,1467220228.828 [PNI_TCM] Loaded 2016-06-29T17:10:28.828Z,1467220228.828 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2016-06-29T17:10:29.190Z,1467220229.190 [Rowe_600LCM] Loaded 2016-06-29T17:10:29.190Z,1467220229.190 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2016-06-29T17:10:29.191Z,1467220229.191 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 409534E0 2016-06-29T17:10:29.192Z,1467220229.192 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 852 2016-06-29T17:10:31.052Z,1467220231.052 [BPC1] Loaded 2016-06-29T17:10:31.053Z,1467220231.053 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2016-06-29T17:10:31.053Z,1467220231.053 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2016-06-29T17:10:31.054Z,1467220231.054 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2016-06-29T17:10:32.630Z,1467220232.630 [BuoyancyServo] Loaded 2016-06-29T17:10:32.630Z,1467220232.630 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2016-06-29T17:10:32.647Z,1467220232.648 [ElevatorServo] Loaded 2016-06-29T17:10:32.648Z,1467220232.648 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2016-06-29T17:10:32.664Z,1467220232.664 [MassServo] Loaded 2016-06-29T17:10:32.664Z,1467220232.664 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2016-06-29T17:10:32.681Z,1467220232.681 [RudderServo] Loaded 2016-06-29T17:10:32.681Z,1467220232.681 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2016-06-29T17:10:32.697Z,1467220232.697 [ThrusterServo] Loaded 2016-06-29T17:10:32.697Z,1467220232.697 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2016-06-29T17:10:32.697Z,1467220232.697 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2016-06-29T17:10:32.698Z,1467220232.698 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2016-06-29T17:10:32.768Z,1467220232.768 [VerticalControl](DEBUG): Construct VerticalControl. 2016-06-29T17:10:32.863Z,1467220232.863 [VerticalControl] Loaded 2016-06-29T17:10:32.863Z,1467220232.863 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2016-06-29T17:10:32.864Z,1467220232.864 [HorizontalControl](DEBUG): Construct HorizontalControl. 2016-06-29T17:10:32.926Z,1467220232.926 [HorizontalControl] Loaded 2016-06-29T17:10:32.926Z,1467220232.926 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2016-06-29T17:10:32.927Z,1467220232.927 [SpeedControl](DEBUG): Construct SpeedControl. 2016-06-29T17:10:32.929Z,1467220232.929 [SpeedControl] Loaded 2016-06-29T17:10:32.929Z,1467220232.929 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2016-06-29T17:10:32.930Z,1467220232.930 [LoopControl](DEBUG): Construct LoopControl. 2016-06-29T17:10:32.930Z,1467220232.930 [LoopControl] Loaded 2016-06-29T17:10:32.931Z,1467220232.931 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2016-06-29T17:10:32.931Z,1467220232.931 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2016-06-29T17:10:32.932Z,1467220232.932 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2016-06-29T17:10:33.050Z,1467220233.050 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2016-06-29T17:10:33.050Z,1467220233.050 [StratificationFrontDetector](DEBUG): (re)initializing 2016-06-29T17:10:33.050Z,1467220233.050 [StratificationFrontDetector] Loaded 2016-06-29T17:10:33.050Z,1467220233.050 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2016-06-29T17:10:33.051Z,1467220233.051 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2016-06-29T17:10:33.052Z,1467220233.052 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2016-06-29T17:10:33.184Z,1467220233.184 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2016-06-29T17:10:33.188Z,1467220233.188 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2016-06-29T17:10:33.189Z,1467220233.189 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2016-06-29T17:10:33.196Z,1467220233.196 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2016-06-29T17:10:33.197Z,1467220233.197 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A5D4E0 2016-06-29T17:10:33.197Z,1467220233.197 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 853 2016-06-29T17:10:33.202Z,1467220233.202 [Supervisor](INFO): Main Thread ID is 763 2016-06-29T17:10:33.202Z,1467220233.202 [Supervisor](DEBUG): Running supervisor. 2016-06-29T17:10:33.203Z,1467220233.203 [CommandLine ThreadHandler](INFO): Handler Thread ID is 854 2016-06-29T17:10:33.206Z,1467220233.206 [controlThread ThreadHandler](INFO): Handler Thread ID is 855 2016-06-29T17:10:33.206Z,1467220233.206 [controlThread](DEBUG): Initializing ControlThread 2016-06-29T17:10:33.207Z,1467220233.207 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2016-06-29T17:10:33.208Z,1467220233.208 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2016-06-29T17:10:33.208Z,1467220233.208 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2016-06-29T17:10:33.208Z,1467220233.208 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2016-06-29T17:10:33.209Z,1467220233.209 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2016-06-29T17:10:33.210Z,1467220233.210 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2016-06-29T17:10:33.210Z,1467220233.210 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2016-06-29T17:10:33.211Z,1467220233.211 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2016-06-29T17:10:33.211Z,1467220233.211 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2016-06-29T17:10:33.212Z,1467220233.212 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2016-06-29T17:10:33.212Z,1467220233.212 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2016-06-29T17:10:33.213Z,1467220233.213 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2016-06-29T17:10:33.213Z,1467220233.213 [NavChart](DEBUG): Initialize NavChart Navigation. 2016-06-29T17:10:33.213Z,1467220233.214 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2016-06-29T17:10:33.214Z,1467220233.214 [SBIT](INFO): Initialize SBIT Component. 2016-06-29T17:10:33.214Z,1467220233.214 [SBIT](IMPORTANT): git: 2015-12-17-108-g5bef090 2016-06-29T17:10:33.215Z,1467220233.215 [SBIT](INFO): git hash: 5bef0906e748577e5d4ac431bf22a986aa172b48 2016-06-29T17:10:33.216Z,1467220233.216 [SBIT](INFO): Kernel Reporting Different Release From Configuration. Kernel Expected: 2.6.27.8 Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty 2016-06-29T17:10:33.217Z,1467220233.217 [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 2016-06-29T17:10:33.218Z,1467220233.217 [SBIT](INFO): Beginning SBIT in 20.000000 seconds. 2016-06-29T17:10:33.218Z,1467220233.218 [IBIT](INFO): Initialize IBIT Component. 2016-06-29T17:10:33.219Z,1467220233.219 [CBIT](DEBUG): Initialize CBIT Component. 2016-06-29T17:10:33.219Z,1467220233.219 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2016-06-29T17:10:33.219Z,1467220233.219 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2016-06-29T17:10:33.220Z,1467220233.220 [logger ThreadHandler](INFO): Handler Thread ID is 856 2016-06-29T17:10:33.247Z,1467220233.247 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 857 2016-06-29T17:10:33.253Z,1467220233.253 [Radio_Surface](INFO): Powering up 2016-06-29T17:10:33.271Z,1467220233.270 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 858 2016-06-29T17:10:33.271Z,1467220233.271 [Rowe_600LCM](INFO): Initializing 2016-06-29T17:10:33.272Z,1467220233.272 [Rowe_600LCM](INFO): Checking LCM 2016-06-29T17:10:33.272Z,1467220233.272 [Rowe_600LCM](INFO): LCM OK 2016-06-29T17:10:33.272Z,1467220233.272 [Rowe_600LCM](INFO): Powering up 2016-06-29T17:10:33.291Z,1467220233.291 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 859 2016-06-29T17:10:33.302Z,1467220233.302 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts 2016-06-29T17:10:33.309Z,1467220233.309 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2016-06-29T17:10:33.311Z,1467220233.311 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2016-06-29T17:10:33.312Z,1467220233.312 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2016-06-29T17:10:33.312Z,1467220233.312 [LoopControl](DEBUG): Initialize LoopControlComponent. 2016-06-29T17:10:33.314Z,1467220233.314 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2016-06-29T17:10:33.340Z,1467220233.340 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2016-06-29T17:10:33.341Z,1467220233.341 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000 2016-06-29T17:10:33.341Z,1467220233.341 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI80M.000 2016-06-29T17:10:33.341Z,1467220233.341 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2016-06-29T17:10:33.342Z,1467220233.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2016-06-29T17:10:33.342Z,1467220233.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2016-06-29T17:10:33.342Z,1467220233.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4IN01M.000 2016-06-29T17:10:33.342Z,1467220233.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI56M.000 2016-06-29T17:10:33.343Z,1467220233.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI57M.000 2016-06-29T17:10:33.343Z,1467220233.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI59M.000 2016-06-29T17:10:33.343Z,1467220233.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000 2016-06-29T17:10:33.343Z,1467220233.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI90M.000 2016-06-29T17:10:33.344Z,1467220233.344 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI03M.000 2016-06-29T17:10:33.344Z,1467220233.344 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI06M.000 2016-06-29T17:10:33.344Z,1467220233.344 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI33M.000 2016-06-29T17:10:33.344Z,1467220233.344 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI34M.000 2016-06-29T17:10:33.345Z,1467220233.345 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2016-06-29T17:10:33.345Z,1467220233.345 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2016-06-29T17:10:33.345Z,1467220233.345 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2016-06-29T17:10:33.345Z,1467220233.345 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2016-06-29T17:10:33.379Z,1467220233.379 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2016-06-29T17:10:33.413Z,1467220233.413 [MissionManager](DEBUG): 2016-06-29T17:10:33.414Z,1467220233.414 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2016-06-29T17:10:33.495Z,1467220233.495 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2016-06-29T17:10:33.496Z,1467220233.496 [Default:A.Wait](DEBUG): Construct Wait. 2016-06-29T17:10:33.510Z,1467220233.510 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2016-06-29T17:10:33.536Z,1467220233.536 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2016-06-29T17:10:33.539Z,1467220233.539 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2016-06-29T17:10:33.560Z,1467220233.560 [Default:E.Execute](DEBUG): Construct Execute. 2016-06-29T17:10:33.580Z,1467220233.579 [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 2016-06-29T17:10:33.585Z,1467220233.585 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,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, 2016-06-29T17:10:33.671Z,1467220233.671 [Depth_Keller](ERROR): Pressure reading out of range: 1895.584351 decibar 2016-06-29T17:10:33.682Z,1467220233.682 [NAL9602](INFO): Powering up NAL9602 2016-06-29T17:10:33.853Z,1467220233.853 [DepthRateCalculator](ERROR): Depth measurement is not active 2016-06-29T17:10:33.932Z,1467220233.932 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:34.174Z,1467220234.174 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:34.288Z,1467220234.288 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2016-06-29T17:10:34.294Z,1467220234.295 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2016-06-29T17:10:34.317Z,1467220234.317 [ElevatorServo](DEBUG): Initializing EZServoServo. 2016-06-29T17:10:34.322Z,1467220234.322 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2016-06-29T17:10:34.336Z,1467220234.336 [MassServo](DEBUG): Initializing EZServoServo. 2016-06-29T17:10:34.343Z,1467220234.342 [MassServo](DEBUG): Initializing MassServo. 2016-06-29T17:10:34.356Z,1467220234.356 [RudderServo](DEBUG): Initializing EZServoServo. 2016-06-29T17:10:34.362Z,1467220234.362 [RudderServo](DEBUG): Initializing RudderServo. 2016-06-29T17:10:34.384Z,1467220234.384 [ThrusterServo](DEBUG): Initializing EZServoServo. 2016-06-29T17:10:34.391Z,1467220234.391 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2016-06-29T17:10:34.673Z,1467220234.673 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:34.675Z,1467220234.675 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:34.896Z,1467220234.896 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:34.898Z,1467220234.898 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:35.238Z,1467220235.238 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2016-06-29T17:10:35.238Z,1467220235.238 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2016-06-29T17:10:35.238Z,1467220235.239 [BuoyancyServo] Communications Fault, FailCount= 1 2016-06-29T17:10:35.239Z,1467220235.239 [BuoyancyServo](ERROR): Communications Fault 2016-06-29T17:10:35.450Z,1467220235.450 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2016-06-29T17:10:35.491Z,1467220235.491 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:35.492Z,1467220235.492 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:35.522Z,1467220235.522 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2016-06-29T17:10:35.523Z,1467220235.523 [BuoyancyServo](INFO): Powering down 2016-06-29T17:10:35.906Z,1467220235.906 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:35.907Z,1467220235.907 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:36.286Z,1467220236.286 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:36.287Z,1467220236.287 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:36.686Z,1467220236.686 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:36.687Z,1467220236.687 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:37.099Z,1467220237.099 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:37.100Z,1467220237.100 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:37.558Z,1467220237.558 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:37.569Z,1467220237.569 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2016-06-29T17:10:37.599Z,1467220237.599 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-06-29T17:10:37.677Z,1467220237.677 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2016-06-29T17:10:37.677Z,1467220237.677 [BuoyancyServo] No Fault, FailCount= 1 2016-06-29T17:10:37.729Z,1467220237.729 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:./bin/roweadcp -dev /dev/ttyB4 -b 38400 >& /dev/null & 2016-06-29T17:10:37.973Z,1467220237.973 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2016-06-29T17:10:37.973Z,1467220237.973 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2016-06-29T17:10:38.584Z,1467220238.584 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2016-06-29T17:10:38.585Z,1467220238.585 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2016-06-29T17:10:44.808Z,1467220244.808 [NAL9602](INFO): NAL9602 initialized 2016-06-29T17:10:53.901Z,1467220253.901 [SBIT](IMPORTANT): Beginning Startup BIT 2016-06-29T17:10:53.936Z,1467220253.936 [CBIT](IMPORTANT): Beginning GF scan 2016-06-29T17:10:54.251Z,1467220254.251 [CBIT](IMPORTANT): Open Volts:2.500889 Open Current:0.000613 2016-06-29T17:10:55.632Z,1467220255.632 [CBIT](IMPORTANT): A0 Volts:2.663994 A0 Current:0.104186 2016-06-29T17:10:57.043Z,1467220257.043 [CBIT](IMPORTANT): A1 Volts:2.021379 A1 Current:-0.305532 2016-06-29T17:10:58.391Z,1467220258.391 [CBIT](IMPORTANT): A2 Volts:2.663662 A2 Current:0.104115 2016-06-29T17:10:58.463Z,1467220258.463 [PNI_TCM](ERROR): CRC does not match. Expected:0x14985 got:0x6465 2016-06-29T17:10:58.831Z,1467220258.831 [PNI_TCM](ERROR): CRC does not match. Expected:0x64237 got:0x6465 2016-06-29T17:10:59.387Z,1467220259.387 [PNI_TCM](ERROR): CRC does not match. Expected:0x50254 got:0x6465 2016-06-29T17:10:59.868Z,1467220259.868 [CBIT](IMPORTANT): A3 Volts:2.622330 A3 Current:0.077441 2016-06-29T17:10:59.978Z,1467220259.978 [PNI_TCM](ERROR): CRC does not match. Expected:0x44322 got:0x6465 2016-06-29T17:10:59.979Z,1467220259.979 [PNI_TCM](ERROR): CRC does not match. Expected:0x43976 got:0x6465 2016-06-29T17:11:00.331Z,1467220260.332 [PNI_TCM](ERROR): CRC does not match. Expected:0x42358 got:0x6465 2016-06-29T17:11:00.731Z,1467220260.731 [PNI_TCM](ERROR): CRC does not match. Expected:0x22712 got:0x6465 2016-06-29T17:11:01.183Z,1467220261.183 [PNI_TCM](ERROR): CRC does not match. Expected:0x7139 got:0x6465 2016-06-29T17:11:01.554Z,1467220261.554 [CBIT](IMPORTANT): B0 Volts:2.388988 B0 Current:-0.070044 2016-06-29T17:11:01.625Z,1467220261.625 [NAL9602](INFO): SBD MO Status=0, MOMSN=807, MT Status=0, MTMSN=0 2016-06-29T17:11:01.625Z,1467220261.625 [NAL9602](INFO): No messages in MT queue 2016-06-29T17:11:01.751Z,1467220261.751 [PNI_TCM](ERROR): CRC does not match. Expected:0x51969 got:0x6465 2016-06-29T17:11:02.007Z,1467220262.007 [PNI_TCM](ERROR): CRC does not match. Expected:0x37591 got:0x6465 2016-06-29T17:11:02.418Z,1467220262.418 [PNI_TCM](ERROR): CRC does not match. Expected:0x51382 got:0x6465 2016-06-29T17:11:02.829Z,1467220262.829 [PNI_TCM](ERROR): CRC does not match. Expected:0x778 got:0x6465 2016-06-29T17:11:03.276Z,1467220263.276 [CBIT](IMPORTANT): B1 Volts:2.281766 B1 Current:-0.138660 2016-06-29T17:11:03.437Z,1467220263.437 [PNI_TCM](ERROR): CRC does not match. Expected:0x53620 got:0x6465 2016-06-29T17:11:03.438Z,1467220263.438 [PNI_TCM](FAULT): Failed to acquire valid data within timeout. 2016-06-29T17:11:03.438Z,1467220263.438 [PNI_TCM] Data Fault, FailCount= 1 2016-06-29T17:11:03.438Z,1467220263.438 [PNI_TCM](ERROR): Data Fault 2016-06-29T17:11:03.516Z,1467220263.516 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.593800 seconds old. 2016-06-29T17:11:03.520Z,1467220263.520 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.586500 seconds old. 2016-06-29T17:11:03.658Z,1467220263.658 [CBIT](ERROR): Data Fault in component: PNI_TCM 2016-06-29T17:11:03.791Z,1467220263.791 [PNI_TCM](INFO): Powering down 2016-06-29T17:11:03.820Z,1467220263.820 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.897700 seconds old. 2016-06-29T17:11:03.824Z,1467220263.824 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.891100 seconds old. 2016-06-29T17:11:04.130Z,1467220264.130 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.209100 seconds old. 2016-06-29T17:11:04.132Z,1467220264.132 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.199600 seconds old. 2016-06-29T17:11:04.526Z,1467220264.526 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.605100 seconds old. 2016-06-29T17:11:04.528Z,1467220264.528 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.595600 seconds old. 2016-06-29T17:11:04.730Z,1467220264.730 [CBIT](IMPORTANT): B2 Volts:2.279112 B2 Current:-0.139826 2016-06-29T17:11:04.989Z,1467220264.989 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.066800 seconds old. 2016-06-29T17:11:05.005Z,1467220265.005 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.072400 seconds old. 2016-06-29T17:11:05.155Z,1467220265.155 [CBIT](INFO): Clearing failed state for component PNI_TCM 2016-06-29T17:11:05.156Z,1467220265.156 [PNI_TCM] No Fault, FailCount= 1 2016-06-29T17:11:05.421Z,1467220265.421 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.499000 seconds old. 2016-06-29T17:11:05.437Z,1467220265.437 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.504300 seconds old. 2016-06-29T17:11:05.834Z,1467220265.834 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.912500 seconds old. 2016-06-29T17:11:05.840Z,1467220265.840 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.907200 seconds old. 2016-06-29T17:11:06.126Z,1467220266.126 [CBIT](IMPORTANT): B3 Volts:1.754701 B3 Current:-0.473624 2016-06-29T17:11:06.185Z,1467220266.185 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.264000 seconds old. 2016-06-29T17:11:06.195Z,1467220266.195 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.262500 seconds old. 2016-06-29T17:11:06.243Z,1467220266.243 [CBIT](FAULT): Low side GF detected mA: CHAN A0 (Batt): 0.104186 CHAN A1 (24V): -0.305532 CHAN A2 (12V): 0.104115 CHAN A3 (5V): 0.077441 CHAN B0 (3.3V): -0.070044 CHAN B1 (3.15aV): -0.138660 CHAN B2 (3.15bV): -0.139826 CHAN B3 (GND): -0.473624 OPEN: 0.000613 Full Scale Calc: 4.765 mA, -1.589 mA 2016-06-29T17:11:06.564Z,1467220266.564 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.642800 seconds old. 2016-06-29T17:11:06.565Z,1467220266.565 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.633200 seconds old. 2016-06-29T17:11:06.986Z,1467220266.986 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 4.065200 seconds old. 2016-06-29T17:11:06.988Z,1467220266.988 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.055600 seconds old. 2016-06-29T17:11:07.452Z,1467220267.452 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 4.529800 seconds old. 2016-06-29T17:11:07.464Z,1467220267.464 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orient