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