2016-06-28T00:38:49.108Z,1467074329.108 [Supervisor](DEBUG): Initializing supervisor.
2016-06-28T00:38:49.111Z,1467074329.111 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0
2016-06-28T00:38:49.111Z,1467074329.111 [SyncHandler](INFO): Protected caller Thread ID is 769
2016-06-28T00:38:49.112Z,1467074329.112 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2016-06-28T00:38:49.113Z,1467074329.113 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0
2016-06-28T00:38:49.113Z,1467074329.113 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 770
2016-06-28T00:38:49.116Z,1467074329.116 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2016-06-28T00:38:49.128Z,1467074329.128 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2016-06-28T00:38:49.129Z,1467074329.129 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0
2016-06-28T00:38:49.129Z,1467074329.129 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 771
2016-06-28T00:38:49.130Z,1467074329.130 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2016-06-28T00:38:49.131Z,1467074329.131 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0
2016-06-28T00:38:49.132Z,1467074329.132 [logger ThreadHandler](INFO): Protected caller Thread ID is 772
2016-06-28T00:38:49.133Z,1467074329.134 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2016-06-28T00:38:49.134Z,1467074329.134 [Supervisor](INFO): Looking for Config files in directory: Config/
2016-06-28T00:38:49.138Z,1467074329.138 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2016-06-28T00:38:49.223Z,1467074329.224 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2016-06-28T00:38:49.534Z,1467074329.534 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2016-06-28T00:38:49.534Z,1467074329.534 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2016-06-28T00:38:49.656Z,1467074329.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2016-06-28T00:38:49.657Z,1467074329.657 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2016-06-28T00:38:49.840Z,1467074329.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2016-06-28T00:38:49.841Z,1467074329.842 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2016-06-28T00:38:49.944Z,1467074329.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2016-06-28T00:38:49.944Z,1467074329.944 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2016-06-28T00:38:50.116Z,1467074330.116 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2016-06-28T00:38:50.118Z,1467074330.118 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2016-06-28T00:38:50.570Z,1467074330.570 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2016-06-28T00:38:50.571Z,1467074330.571 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2016-06-28T00:38:50.842Z,1467074330.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2016-06-28T00:38:50.842Z,1467074330.842 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2016-06-28T00:38:50.930Z,1467074330.930 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2016-06-28T00:38:50.933Z,1467074330.933 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2016-06-28T00:38:51.062Z,1467074331.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2016-06-28T00:38:51.063Z,1467074331.063 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2016-06-28T00:38:51.251Z,1467074331.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2016-06-28T00:38:51.251Z,1467074331.251 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2016-06-28T00:38:51.665Z,1467074331.665 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2016-06-28T00:38:51.666Z,1467074331.666 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2016-06-28T00:38:56.337Z,1467074336.337 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2016-06-28T00:38:56.338Z,1467074336.338 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2016-06-28T00:38:56.634Z,1467074336.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2016-06-28T00:38:56.635Z,1467074336.635 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2016-06-28T00:38:56.755Z,1467074336.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2016-06-28T00:38:56.757Z,1467074336.757 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/
2016-06-28T00:38:58.416Z,1467074338.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg
2016-06-28T00:38:58.610Z,1467074338.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Navigation.cfg
2016-06-28T00:38:58.705Z,1467074338.705 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg
2016-06-28T00:38:58.794Z,1467074338.794 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg
2016-06-28T00:38:58.894Z,1467074338.894 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg
2016-06-28T00:38:58.983Z,1467074338.983 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg
2016-06-28T00:38:59.124Z,1467074339.124 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg
2016-06-28T00:38:59.222Z,1467074339.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg
2016-06-28T00:38:59.383Z,1467074339.383 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg
2016-06-28T00:38:59.612Z,1467074339.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2016-06-28T00:38:59.613Z,1467074339.613 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg
2016-06-28T00:38:59.830Z,1467074339.830 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg
2016-06-28T00:38:59.933Z,1467074339.934 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2016-06-28T00:38:59.937Z,1467074339.937 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2016-06-28T00:38:59.977Z,1467074339.977 [DepthRateCalculator] Loaded
2016-06-28T00:38:59.977Z,1467074339.977 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2016-06-28T00:38:59.984Z,1467074339.984 [PitchRateCalculator] Loaded
2016-06-28T00:38:59.985Z,1467074339.985 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2016-06-28T00:38:59.996Z,1467074339.996 [SpeedCalculator] Loaded
2016-06-28T00:38:59.997Z,1467074339.997 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2016-06-28T00:39:00.013Z,1467074340.013 [TempGradientCalculator] Loaded
2016-06-28T00:39:00.013Z,1467074340.013 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2016-06-28T00:39:00.029Z,1467074340.029 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2016-06-28T00:39:00.030Z,1467074340.030 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2016-06-28T00:39:00.036Z,1467074340.036 [YawRateCalculator] Loaded
2016-06-28T00:39:00.036Z,1467074340.036 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2016-06-28T00:39:00.036Z,1467074340.036 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2016-06-28T00:39:00.037Z,1467074340.037 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2016-06-28T00:39:00.161Z,1467074340.161 [DeadReckonUsingMultipleVelocitySources] Loaded
2016-06-28T00:39:00.161Z,1467074340.161 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2016-06-28T00:39:00.216Z,1467074340.216 [DeadReckonUsingSpeedCalculator] Loaded
2016-06-28T00:39:00.217Z,1467074340.217 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2016-06-28T00:39:00.234Z,1467074340.234 [NavChart] Loaded
2016-06-28T00:39:00.234Z,1467074340.234 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2016-06-28T00:39:00.239Z,1467074340.239 [UniversalFixResidualReporter] Loaded
2016-06-28T00:39:00.239Z,1467074340.239 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2016-06-28T00:39:00.239Z,1467074340.239 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2016-06-28T00:39:00.240Z,1467074340.240 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2016-06-28T00:39:00.379Z,1467074340.379 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2016-06-28T00:39:00.380Z,1467074340.380 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2016-06-28T00:39:00.420Z,1467074340.420 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2016-06-28T00:39:00.421Z,1467074340.421 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2016-06-28T00:39:00.430Z,1467074340.430 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2016-06-28T00:39:00.431Z,1467074340.431 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2016-06-28T00:39:00.706Z,1467074340.706 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2016-06-28T00:39:00.707Z,1467074340.707 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2016-06-28T00:39:00.855Z,1467074340.855 [SBIT](DEBUG): Construct Startup Built In Test.
2016-06-28T00:39:00.888Z,1467074340.888 [SBIT] Loaded
2016-06-28T00:39:00.888Z,1467074340.888 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2016-06-28T00:39:00.889Z,1467074340.889 [IBIT](DEBUG): Construct Initiated Built In Test.
2016-06-28T00:39:00.917Z,1467074340.917 [IBIT] Loaded
2016-06-28T00:39:00.918Z,1467074340.918 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2016-06-28T00:39:00.921Z,1467074340.921 [CBIT](DEBUG): Construct Continuous Built In Test.
2016-06-28T00:39:01.076Z,1467074341.076 [CBIT] Loaded
2016-06-28T00:39:01.076Z,1467074341.076 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2016-06-28T00:39:01.077Z,1467074341.077 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2016-06-28T00:39:01.078Z,1467074341.078 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2016-06-28T00:39:01.697Z,1467074341.697 [DataOverHttps] Loaded
2016-06-28T00:39:01.697Z,1467074341.697 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2016-06-28T00:39:01.723Z,1467074341.723 [Depth_Keller] Loaded
2016-06-28T00:39:01.723Z,1467074341.723 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2016-06-28T00:39:01.817Z,1467074341.817 [NAL9602] Loaded
2016-06-28T00:39:01.817Z,1467074341.817 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2016-06-28T00:39:01.827Z,1467074341.827 [Onboard] Loaded
2016-06-28T00:39:01.827Z,1467074341.828 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2016-06-28T00:39:01.835Z,1467074341.835 [Radio_Surface] Loaded
2016-06-28T00:39:01.835Z,1467074341.835 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2016-06-28T00:39:01.836Z,1467074341.836 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409234E0
2016-06-28T00:39:01.837Z,1467074341.837 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 852
2016-06-28T00:39:02.032Z,1467074342.032 [PNI_TCM] Loaded
2016-06-28T00:39:02.033Z,1467074342.033 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2016-06-28T00:39:02.394Z,1467074342.394 [Rowe_600LCM] Loaded
2016-06-28T00:39:02.394Z,1467074342.394 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2016-06-28T00:39:02.395Z,1467074342.395 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 409534E0
2016-06-28T00:39:02.396Z,1467074342.396 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 853
2016-06-28T00:39:04.241Z,1467074344.241 [BPC1] Loaded
2016-06-28T00:39:04.241Z,1467074344.241 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2016-06-28T00:39:04.242Z,1467074344.241 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2016-06-28T00:39:04.242Z,1467074344.242 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2016-06-28T00:39:04.373Z,1467074344.373 [BuoyancyServo] Loaded
2016-06-28T00:39:04.373Z,1467074344.373 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2016-06-28T00:39:04.390Z,1467074344.390 [ElevatorServo] Loaded
2016-06-28T00:39:04.390Z,1467074344.390 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2016-06-28T00:39:04.406Z,1467074344.406 [MassServo] Loaded
2016-06-28T00:39:04.406Z,1467074344.406 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2016-06-28T00:39:04.423Z,1467074344.423 [RudderServo] Loaded
2016-06-28T00:39:04.423Z,1467074344.423 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2016-06-28T00:39:04.439Z,1467074344.439 [ThrusterServo] Loaded
2016-06-28T00:39:04.439Z,1467074344.439 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2016-06-28T00:39:04.440Z,1467074344.440 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2016-06-28T00:39:04.440Z,1467074344.440 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2016-06-28T00:39:07.029Z,1467074347.029 [VerticalControl](DEBUG): Construct VerticalControl.
2016-06-28T00:39:07.124Z,1467074347.124 [VerticalControl] Loaded
2016-06-28T00:39:07.124Z,1467074347.124 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2016-06-28T00:39:07.125Z,1467074347.125 [HorizontalControl](DEBUG): Construct HorizontalControl.
2016-06-28T00:39:07.187Z,1467074347.187 [HorizontalControl] Loaded
2016-06-28T00:39:07.188Z,1467074347.188 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2016-06-28T00:39:07.188Z,1467074347.188 [SpeedControl](DEBUG): Construct SpeedControl.
2016-06-28T00:39:07.190Z,1467074347.190 [SpeedControl] Loaded
2016-06-28T00:39:07.191Z,1467074347.191 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2016-06-28T00:39:07.191Z,1467074347.191 [LoopControl](DEBUG): Construct LoopControl.
2016-06-28T00:39:07.192Z,1467074347.192 [LoopControl] Loaded
2016-06-28T00:39:07.192Z,1467074347.192 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2016-06-28T00:39:07.193Z,1467074347.193 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2016-06-28T00:39:07.193Z,1467074347.193 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2016-06-28T00:39:07.310Z,1467074347.310 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2016-06-28T00:39:07.311Z,1467074347.311 [StratificationFrontDetector](DEBUG): (re)initializing
2016-06-28T00:39:07.311Z,1467074347.311 [StratificationFrontDetector] Loaded
2016-06-28T00:39:07.311Z,1467074347.311 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2016-06-28T00:39:07.312Z,1467074347.312 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2016-06-28T00:39:07.312Z,1467074347.312 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2016-06-28T00:39:07.445Z,1467074347.445 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2016-06-28T00:39:07.449Z,1467074347.449 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2016-06-28T00:39:07.450Z,1467074347.450 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2016-06-28T00:39:07.456Z,1467074347.457 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2016-06-28T00:39:07.458Z,1467074347.458 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A5D4E0
2016-06-28T00:39:07.458Z,1467074347.458 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 854
2016-06-28T00:39:07.463Z,1467074347.463 [Supervisor](INFO): Main Thread ID is 764
2016-06-28T00:39:07.463Z,1467074347.463 [Supervisor](DEBUG): Running supervisor.
2016-06-28T00:39:07.464Z,1467074347.464 [CommandLine ThreadHandler](INFO): Handler Thread ID is 855
2016-06-28T00:39:07.467Z,1467074347.467 [controlThread ThreadHandler](INFO): Handler Thread ID is 856
2016-06-28T00:39:07.467Z,1467074347.467 [controlThread](DEBUG): Initializing ControlThread
2016-06-28T00:39:07.468Z,1467074347.468 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-06-28T00:39:07.468Z,1467074347.468 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2016-06-28T00:39:07.469Z,1467074347.469 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2016-06-28T00:39:07.469Z,1467074347.469 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2016-06-28T00:39:07.470Z,1467074347.470 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2016-06-28T00:39:07.470Z,1467074347.470 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2016-06-28T00:39:07.471Z,1467074347.471 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2016-06-28T00:39:07.472Z,1467074347.472 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2016-06-28T00:39:07.472Z,1467074347.472 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2016-06-28T00:39:07.472Z,1467074347.472 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2016-06-28T00:39:07.473Z,1467074347.473 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2016-06-28T00:39:07.473Z,1467074347.473 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2016-06-28T00:39:07.474Z,1467074347.474 [NavChart](DEBUG): Initialize NavChart Navigation.
2016-06-28T00:39:07.474Z,1467074347.474 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2016-06-28T00:39:07.474Z,1467074347.474 [SBIT](INFO): Initialize SBIT Component.
2016-06-28T00:39:07.475Z,1467074347.475 [SBIT](IMPORTANT): git: 2015-12-17-109-g257a154
2016-06-28T00:39:07.475Z,1467074347.475 [SBIT](INFO): git hash: 257a1547f8111cca91b00dd2487919c4d9436f7c
2016-06-28T00:39:07.477Z,1467074347.477 [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-28T00:39:07.477Z,1467074347.477 [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-28T00:39:07.478Z,1467074347.478 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2016-06-28T00:39:07.478Z,1467074347.478 [IBIT](INFO): Initialize IBIT Component.
2016-06-28T00:39:07.479Z,1467074347.479 [CBIT](DEBUG): Initialize CBIT Component.
2016-06-28T00:39:07.479Z,1467074347.479 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2016-06-28T00:39:07.480Z,1467074347.480 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2016-06-28T00:39:07.481Z,1467074347.480 [logger ThreadHandler](INFO): Handler Thread ID is 857
2016-06-28T00:39:07.508Z,1467074347.508 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 858
2016-06-28T00:39:07.514Z,1467074347.514 [Radio_Surface](INFO): Powering up
2016-06-28T00:39:07.532Z,1467074347.532 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 859
2016-06-28T00:39:07.532Z,1467074347.532 [Rowe_600LCM](INFO): Initializing
2016-06-28T00:39:07.533Z,1467074347.533 [Rowe_600LCM](INFO): Checking LCM
2016-06-28T00:39:07.533Z,1467074347.533 [Rowe_600LCM](INFO): LCM OK
2016-06-28T00:39:07.533Z,1467074347.533 [Rowe_600LCM](INFO): Powering up
2016-06-28T00:39:07.552Z,1467074347.552 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 860
2016-06-28T00:39:07.568Z,1467074347.569 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts
2016-06-28T00:39:07.572Z,1467074347.572 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2016-06-28T00:39:07.574Z,1467074347.574 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2016-06-28T00:39:07.575Z,1467074347.575 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2016-06-28T00:39:07.575Z,1467074347.575 [LoopControl](DEBUG): Initialize LoopControlComponent.
2016-06-28T00:39:07.577Z,1467074347.577 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2016-06-28T00:39:07.631Z,1467074347.631 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2016-06-28T00:39:07.638Z,1467074347.638 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2016-06-28T00:39:07.638Z,1467074347.638 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000
2016-06-28T00:39:07.638Z,1467074347.638 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI80M.000
2016-06-28T00:39:07.639Z,1467074347.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2016-06-28T00:39:07.639Z,1467074347.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2016-06-28T00:39:07.639Z,1467074347.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2016-06-28T00:39:07.640Z,1467074347.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4IN01M.000
2016-06-28T00:39:07.640Z,1467074347.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI56M.000
2016-06-28T00:39:07.640Z,1467074347.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI57M.000
2016-06-28T00:39:07.641Z,1467074347.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI59M.000
2016-06-28T00:39:07.641Z,1467074347.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000
2016-06-28T00:39:07.641Z,1467074347.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI90M.000
2016-06-28T00:39:07.641Z,1467074347.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI03M.000
2016-06-28T00:39:07.641Z,1467074347.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI06M.000
2016-06-28T00:39:07.641Z,1467074347.641 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI33M.000
2016-06-28T00:39:07.642Z,1467074347.642 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI34M.000
2016-06-28T00:39:07.642Z,1467074347.642 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2016-06-28T00:39:07.642Z,1467074347.642 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2016-06-28T00:39:07.642Z,1467074347.642 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2016-06-28T00:39:07.643Z,1467074347.643 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2016-06-28T00:39:07.674Z,1467074347.674 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2016-06-28T00:39:07.675Z,1467074347.675 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2016-06-28T00:39:08.586Z,1467074348.586 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2016-06-28T00:39:08.587Z,1467074348.587 [Default:A.Wait](DEBUG): Construct Wait.
2016-06-28T00:39:08.605Z,1467074348.605 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2016-06-28T00:39:08.631Z,1467074348.631 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2016-06-28T00:39:08.634Z,1467074348.634 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2016-06-28T00:39:08.655Z,1467074348.655 [Default:E.Execute](DEBUG): Construct Execute.
2016-06-28T00:39:08.659Z,1467074348.659 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Guidance="Tethys/Guidance"
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Sequence/>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2016-06-28T00:39:08.676Z,1467074348.676 [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-28T00:39:08.778Z,1467074348.778 [NAL9602](INFO): Powering up NAL9602
2016-06-28T00:39:09.061Z,1467074349.061 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:09.232Z,1467074349.232 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:09.325Z,1467074349.325 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2016-06-28T00:39:09.332Z,1467074349.332 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2016-06-28T00:39:09.338Z,1467074349.338 [ElevatorServo](DEBUG): Initializing EZServoServo.
2016-06-28T00:39:09.344Z,1467074349.344 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2016-06-28T00:39:09.350Z,1467074349.349 [MassServo](DEBUG): Initializing EZServoServo.
2016-06-28T00:39:09.356Z,1467074349.356 [MassServo](DEBUG): Initializing MassServo.
2016-06-28T00:39:09.361Z,1467074349.362 [RudderServo](DEBUG): Initializing EZServoServo.
2016-06-28T00:39:09.368Z,1467074349.368 [RudderServo](DEBUG): Initializing RudderServo.
2016-06-28T00:39:09.373Z,1467074349.374 [ThrusterServo](DEBUG): Initializing EZServoServo.
2016-06-28T00:39:09.380Z,1467074349.380 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2016-06-28T00:39:09.420Z,1467074349.420 [CommandLine](FAULT): Scheduling is paused
2016-06-28T00:39:09.672Z,1467074349.672 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:09.673Z,1467074349.673 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:09.905Z,1467074349.905 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:09.906Z,1467074349.906 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:10.252Z,1467074350.252 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2016-06-28T00:39:10.252Z,1467074350.252 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2016-06-28T00:39:10.252Z,1467074350.252 [BuoyancyServo] Communications Fault, FailCount= 1
2016-06-28T00:39:10.252Z,1467074350.252 [BuoyancyServo](ERROR): Communications Fault
2016-06-28T00:39:10.463Z,1467074350.463 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2016-06-28T00:39:10.531Z,1467074350.531 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:10.540Z,1467074350.540 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:10.549Z,1467074350.549 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2016-06-28T00:39:10.550Z,1467074350.550 [BuoyancyServo](INFO): Powering down
2016-06-28T00:39:10.915Z,1467074350.915 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:10.928Z,1467074350.928 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:11.299Z,1467074351.299 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:11.300Z,1467074351.300 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:11.716Z,1467074351.716 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:11.718Z,1467074351.718 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:11.939Z,1467074351.939 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2016-06-28T00:39:12.031Z,1467074352.031 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:./bin/roweadcp -dev /dev/ttyB4 -b 38400 >& /dev/null &
2016-06-28T00:39:12.138Z,1467074352.138 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:12.152Z,1467074352.152 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-06-28T00:39:12.673Z,1467074352.673 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2016-06-28T00:39:12.673Z,1467074352.673 [BuoyancyServo] No Fault, FailCount= 1
2016-06-28T00:39:12.856Z,1467074352.856 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2016-06-28T00:39:12.857Z,1467074352.857 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2016-06-28T00:39:12.989Z,1467074352.989 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2016-06-28T00:39:12.990Z,1467074352.990 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2016-06-28T00:39:13.839Z,1467074353.839 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2016-06-28T00:39:13.840Z,1467074353.840 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2016-06-28T00:39:13.840Z,1467074353.840 [BuoyancyServo] Communications Fault, FailCount= 2
2016-06-28T00:39:13.840Z,1467074353.840 [BuoyancyServo](ERROR): Communications Fault
2016-06-28T00:39:13.995Z,1467074353.995 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2016-06-28T00:39:14.128Z,1467074354.128 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2016-06-28T00:39:14.129Z,1467074354.129 [BuoyancyServo](INFO): Powering down
2016-06-28T00:39:16.075Z,1467074356.075 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2016-06-28T00:39:16.075Z,1467074356.075 [BuoyancyServo] No Fault, FailCount= 2
2016-06-28T00:39:16.477Z,1467074356.477 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2016-06-28T00:39:16.478Z,1467074356.478 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2016-06-28T00:39:19.702Z,1467074359.702 [NAL9602](INFO): NAL9602 initialized
2016-06-28T00:39:20.277Z,1467074360.277 [PNI_TCM](ERROR): CRC does not match. Expected:0x45672 got:0x29432
2016-06-28T00:39:20.888Z,1467074360.888 [PNI_TCM](ERROR): CRC does not match. Expected:0x8334 got:0x29430
2016-06-28T00:39:21.479Z,1467074361.479 [PNI_TCM](ERROR): CRC does not match. Expected:0x25299 got:0x29430
2016-06-28T00:39:21.516Z,1467074361.516 [PNI_TCM](ERROR): CRC does not match. Expected:0x25299 got:0x29421
2016-06-28T00:39:21.900Z,1467074361.900 [PNI_TCM](ERROR): CRC does not match. Expected:0x20311 got:0x29422
2016-06-28T00:39:22.308Z,1467074362.308 [PNI_TCM](ERROR): CRC does not match. Expected:0x27802 got:0x29427
2016-06-28T00:39:22.553Z,1467074362.553 [PNI_TCM](ERROR): CRC does not match. Expected:0x1668 got:0x29433
2016-06-28T00:39:22.964Z,1467074362.964 [PNI_TCM](ERROR): CRC does not match. Expected:0x52778 got:0x29421
2016-06-28T00:39:23.456Z,1467074363.456 [PNI_TCM](ERROR): CRC does not match. Expected:0x20311 got:0x29416
2016-06-28T00:39:23.826Z,1467074363.826 [PNI_TCM](ERROR): CRC does not match. Expected:0x11008 got:0x29420
2016-06-28T00:39:24.242Z,1467074364.241 [PNI_TCM](ERROR): CRC does not match. Expected:0x41459 got:0x29423
2016-06-28T00:39:24.558Z,1467074364.557 [PNI_TCM](ERROR): CRC does not match. Expected:0x33342 got:0x29412
2016-06-28T00:39:24.967Z,1467074364.967 [PNI_TCM](ERROR): CRC does not match. Expected:0x42036 got:0x29418
2016-06-28T00:39:25.420Z,1467074365.420 [PNI_TCM](ERROR): CRC does not match. Expected:0x58985 got:0x29417
2016-06-28T00:39:25.832Z,1467074365.832 [PNI_TCM](ERROR): CRC does not match. Expected:0x50596 got:0x29419
2016-06-28T00:39:26.227Z,1467074366.227 [PNI_TCM](ERROR): CRC does not match. Expected:0x2253 got:0x29423
2016-06-28T00:39:26.578Z,1467074366.578 [PNI_TCM](ERROR): CRC does not match. Expected:0x33342 got:0x29432
2016-06-28T00:39:26.952Z,1467074366.952 [PNI_TCM](ERROR): CRC does not match. Expected:0x8334 got:0x29422
2016-06-28T00:39:27.531Z,1467074367.531 [PNI_TCM](ERROR): CRC does not match. Expected:0x27802 got:0x29420
2016-06-28T00:39:28.065Z,1467074368.065 [PNI_TCM](ERROR): CRC does not match. Expected:0x41459 got:0x29422
2016-06-28T00:39:28.217Z,1467074368.217 [SBIT](IMPORTANT): Beginning Startup BIT
2016-06-28T00:39:28.260Z,1467074368.260 [CBIT](IMPORTANT): Beginning GF scan
2016-06-28T00:39:28.361Z,1467074368.361 [PNI_TCM](ERROR): CRC does not match. Expected:0x27802 got:0x29422
2016-06-28T00:39:28.572Z,1467074368.572 [CBIT](IMPORTANT): Open Volts:2.499778
Open Current:0.001062
2016-06-28T00:39:28.720Z,1467074368.720 [PNI_TCM](ERROR): CRC does not match. Expected:0x27802 got:0x29428
2016-06-28T00:39:29.112Z,1467074369.112 [PNI_TCM](ERROR): CRC does not match. Expected:0x44986 got:0x29435
2016-06-28T00:39:29.501Z,1467074369.501 [PNI_TCM](ERROR): CRC does not match. Expected:0x835 got:0x29400
2016-06-28T00:39:29.501Z,1467074369.501 [PNI_TCM](FAULT): Failed to acquire valid data within timeout.
2016-06-28T00:39:29.501Z,1467074369.501 [PNI_TCM] Data Fault, FailCount= 1
2016-06-28T00:39:29.501Z,1467074369.501 [PNI_TCM](ERROR): Data Fault
2016-06-28T00:39:29.520Z,1467074369.520 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.350800 seconds old.
2016-06-28T00:39:29.521Z,1467074369.521 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.351200 seconds old.
2016-06-28T00:39:29.675Z,1467074369.675 [CBIT](ERROR): Data Fault in component: PNI_TCM
2016-06-28T00:39:29.870Z,1467074369.870 [CBIT](IMPORTANT): A0 Volts:2.669466
A0 Current:0.112619
2016-06-28T00:39:29.980Z,1467074369.980 [PNI_TCM](INFO): Powering down
2016-06-28T00:39:30.125Z,1467074370.125 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.955200 seconds old.
2016-06-28T00:39:30.138Z,1467074370.138 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.966100 seconds old.
2016-06-28T00:39:30.808Z,1467074370.808 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.639000 seconds old.
2016-06-28T00:39:30.809Z,1467074370.809 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.639400 seconds old.
2016-06-28T00:39:31.116Z,1467074371.116 [CBIT](IMPORTANT): A1 Volts:2.005672
A1 Current:-0.315008
2016-06-28T00:39:31.279Z,1467074371.279 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.109400 seconds old.
2016-06-28T00:39:31.309Z,1467074371.309 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.138000 seconds old.
2016-06-28T00:39:31.539Z,1467074371.539 [CBIT](INFO): Clearing failed state for component PNI_TCM
2016-06-28T00:39:31.540Z,1467074371.540 [PNI_TCM] No Fault, FailCount= 1
2016-06-28T00:39:31.747Z,1467074371.747 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.576600 seconds old.
2016-06-28T00:39:31.757Z,1467074371.757 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.586500 seconds old.
2016-06-28T00:39:32.169Z,1467074372.169 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.999000 seconds old.
2016-06-28T00:39:32.181Z,1467074372.181 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.010800 seconds old.
2016-06-28T00:39:32.552Z,1467074372.552 [CBIT](IMPORTANT): A2 Volts:2.668960
A2 Current:0.107304
2016-06-28T00:39:32.664Z,1467074372.664 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.494600 seconds old.
2016-06-28T00:39:32.665Z,1467074372.665 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.495100 seconds old.
2016-06-28T00:39:33.006Z,1467074373.006 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.837200 seconds old.
2016-06-28T00:39:33.008Z,1467074373.008 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.837800 seconds old