2015-01-22T18:28:44.985Z,1421951324.985 [Supervisor](DEBUG): Initializing supervisor.
2015-01-22T18:28:44.987Z,1421951324.987 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-22T18:28:44.988Z,1421951324.988 [SyncHandler](INFO): Protected caller Thread ID is 768
2015-01-22T18:28:44.988Z,1421951324.988 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-22T18:28:44.989Z,1421951324.989 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-22T18:28:44.990Z,1421951324.990 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 769
2015-01-22T18:28:44.993Z,1421951324.993 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-22T18:28:45.004Z,1421951325.004 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-22T18:28:45.005Z,1421951325.005 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-22T18:28:45.006Z,1421951325.006 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 770
2015-01-22T18:28:45.007Z,1421951325.007 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-22T18:28:45.008Z,1421951325.008 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-22T18:28:45.008Z,1421951325.008 [logger ThreadHandler](INFO): Protected caller Thread ID is 771
2015-01-22T18:28:45.010Z,1421951325.010 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-22T18:28:45.010Z,1421951325.010 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-22T18:28:45.014Z,1421951325.014 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-22T18:28:45.383Z,1421951325.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-22T18:28:45.385Z,1421951325.385 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-22T18:28:45.556Z,1421951325.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-22T18:28:45.556Z,1421951325.556 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-22T18:28:45.670Z,1421951325.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-22T18:28:45.671Z,1421951325.671 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-22T18:28:45.799Z,1421951325.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-22T18:28:45.800Z,1421951325.800 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-22T18:28:45.889Z,1421951325.889 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-22T18:28:46.062Z,1421951326.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-22T18:28:46.063Z,1421951326.063 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-22T18:28:46.152Z,1421951326.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-22T18:28:46.153Z,1421951326.153 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-22T18:28:46.374Z,1421951326.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-22T18:28:46.375Z,1421951326.375 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-22T18:28:46.769Z,1421951326.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-22T18:28:46.770Z,1421951326.770 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-22T18:28:47.109Z,1421951327.109 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-22T18:28:47.109Z,1421951327.109 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-22T18:28:47.652Z,1421951327.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-22T18:28:47.653Z,1421951327.653 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-22T18:28:47.882Z,1421951327.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-22T18:28:47.883Z,1421951327.883 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-22T18:28:47.992Z,1421951327.992 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-22T18:28:47.993Z,1421951327.993 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-22T18:28:48.453Z,1421951328.453 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-22T18:28:48.453Z,1421951328.453 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-22T18:28:48.570Z,1421951328.570 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-22T18:28:48.572Z,1421951328.572 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-22T18:28:48.576Z,1421951328.576 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-22T18:28:48.832Z,1421951328.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-22T18:29:02.002Z,1421951342.002 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-22T18:29:02.448Z,1421951342.448 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-22T18:29:03.332Z,1421951343.332 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-22T18:29:03.434Z,1421951343.434 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-22T18:29:03.547Z,1421951343.547 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-22T18:29:03.699Z,1421951343.699 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-22T18:29:03.884Z,1421951343.884 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-22T18:29:03.993Z,1421951343.993 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-22T18:29:04.088Z,1421951344.088 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-22T18:29:04.194Z,1421951344.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-22T18:29:04.294Z,1421951344.294 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-22T18:29:04.491Z,1421951344.491 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-01-22T18:29:04.498Z,1421951344.498 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-22T18:29:04.579Z,1421951344.579 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-22T18:29:04.705Z,1421951344.705 [VerticalControl] Loaded
2015-01-22T18:29:04.705Z,1421951344.705 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-22T18:29:04.706Z,1421951344.706 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-22T18:29:04.782Z,1421951344.782 [HorizontalControl] Loaded
2015-01-22T18:29:04.782Z,1421951344.782 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-22T18:29:04.783Z,1421951344.783 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-22T18:29:04.789Z,1421951344.789 [SpeedControl] Loaded
2015-01-22T18:29:04.789Z,1421951344.789 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-22T18:29:04.790Z,1421951344.790 [LoopControl](DEBUG): Construct LoopControl.
2015-01-22T18:29:04.791Z,1421951344.791 [LoopControl] Loaded
2015-01-22T18:29:04.791Z,1421951344.791 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-22T18:29:04.791Z,1421951344.792 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-22T18:29:04.792Z,1421951344.792 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-22T18:29:04.926Z,1421951344.926 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-22T18:29:04.938Z,1421951344.938 [SBIT] Loaded
2015-01-22T18:29:04.939Z,1421951344.939 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-22T18:29:04.939Z,1421951344.939 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-22T18:29:04.970Z,1421951344.970 [IBIT] Loaded
2015-01-22T18:29:04.970Z,1421951344.970 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-22T18:29:04.972Z,1421951344.972 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-22T18:29:05.099Z,1421951345.099 [CBIT] Loaded
2015-01-22T18:29:05.100Z,1421951345.100 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-22T18:29:05.100Z,1421951345.100 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-22T18:29:05.101Z,1421951345.101 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-22T18:29:05.131Z,1421951345.131 [DepthRateCalculator] Loaded
2015-01-22T18:29:05.131Z,1421951345.131 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-22T18:29:05.137Z,1421951345.137 [PitchRateCalculator] Loaded
2015-01-22T18:29:05.138Z,1421951345.138 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-22T18:29:05.150Z,1421951345.150 [SpeedCalculator] Loaded
2015-01-22T18:29:05.150Z,1421951345.150 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-22T18:29:05.168Z,1421951345.168 [TempGradientCalculator] Loaded
2015-01-22T18:29:05.168Z,1421951345.168 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-22T18:29:05.174Z,1421951345.174 [YawRateCalculator] Loaded
2015-01-22T18:29:05.174Z,1421951345.174 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-22T18:29:05.175Z,1421951345.175 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-22T18:29:05.175Z,1421951345.175 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-22T18:29:06.632Z,1421951346.632 [HFRCMReconstructedInterpolator] Loaded
2015-01-22T18:29:06.632Z,1421951346.632 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2015-01-22T18:29:06.633Z,1421951346.633 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-22T18:29:06.635Z,1421951346.635 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-22T18:29:06.938Z,1421951346.938 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-22T18:29:06.938Z,1421951346.938 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-22T18:29:07.051Z,1421951347.051 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-01-22T18:29:07.051Z,1421951347.051 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-01-22T18:29:07.099Z,1421951347.099 [DeadReckonUsingSpeedCalculator] Loaded
2015-01-22T18:29:07.100Z,1421951347.100 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-01-22T18:29:07.118Z,1421951347.118 [NavChart] Loaded
2015-01-22T18:29:07.118Z,1421951347.118 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-22T18:29:07.123Z,1421951347.123 [UniversalFixResidualReporter] Loaded
2015-01-22T18:29:07.124Z,1421951347.124 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-22T18:29:07.124Z,1421951347.124 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-22T18:29:07.125Z,1421951347.125 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-22T18:29:07.134Z,1421951347.134 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-22T18:29:07.135Z,1421951347.135 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-22T18:29:07.259Z,1421951347.259 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-22T18:29:07.260Z,1421951347.260 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-22T18:29:07.974Z,1421951347.974 [AHRS_sp3003D] Loaded
2015-01-22T18:29:07.975Z,1421951347.975 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2015-01-22T18:29:08.139Z,1421951348.139 [DataOverHttps] Loaded
2015-01-22T18:29:08.140Z,1421951348.140 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-22T18:29:08.154Z,1421951348.154 [Depth_Keller] Loaded
2015-01-22T18:29:08.154Z,1421951348.154 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-22T18:29:08.255Z,1421951348.255 [NAL9602] Loaded
2015-01-22T18:29:08.255Z,1421951348.255 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-22T18:29:08.300Z,1421951348.300 [Onboard] Loaded
2015-01-22T18:29:08.300Z,1421951348.300 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-22T18:29:08.308Z,1421951348.308 [Radio_Surface] Loaded
2015-01-22T18:29:08.308Z,1421951348.308 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-22T18:29:08.309Z,1421951348.309 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408024E0
2015-01-22T18:29:08.310Z,1421951348.310 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 853
2015-01-22T18:29:10.314Z,1421951350.314 [BPC1] Loaded
2015-01-22T18:29:10.315Z,1421951350.315 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-22T18:29:10.315Z,1421951350.315 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-22T18:29:10.316Z,1421951350.316 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-22T18:29:18.021Z,1421951358.021 [BuoyancyServo] Loaded
2015-01-22T18:29:18.022Z,1421951358.022 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-22T18:29:18.034Z,1421951358.034 [ElevatorServo] Loaded
2015-01-22T18:29:18.035Z,1421951358.035 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-22T18:29:18.047Z,1421951358.047 [RudderServo] Loaded
2015-01-22T18:29:18.047Z,1421951358.047 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-22T18:29:18.060Z,1421951358.060 [ThrusterServo] Loaded
2015-01-22T18:29:18.060Z,1421951358.060 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-22T18:29:18.060Z,1421951358.060 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-22T18:29:18.061Z,1421951358.061 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-22T18:29:18.212Z,1421951358.212 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-22T18:29:18.212Z,1421951358.212 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-22T18:29:18.255Z,1421951358.255 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-22T18:29:18.257Z,1421951358.257 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-22T18:29:18.258Z,1421951358.258 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-22T18:29:18.264Z,1421951358.264 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-22T18:29:18.265Z,1421951358.265 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408B34E0
2015-01-22T18:29:18.265Z,1421951358.265 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 854
2015-01-22T18:29:18.270Z,1421951358.270 [Supervisor](INFO): Main Thread ID is 766
2015-01-22T18:29:18.270Z,1421951358.270 [Supervisor](DEBUG): Running supervisor.
2015-01-22T18:29:18.271Z,1421951358.271 [CommandLine ThreadHandler](INFO): Handler Thread ID is 855
2015-01-22T18:29:18.274Z,1421951358.274 [controlThread ThreadHandler](INFO): Handler Thread ID is 856
2015-01-22T18:29:18.274Z,1421951358.274 [controlThread](DEBUG): Initializing ControlThread
2015-01-22T18:29:18.275Z,1421951358.275 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-22T18:29:18.277Z,1421951358.277 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-22T18:29:18.277Z,1421951358.277 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-22T18:29:18.278Z,1421951358.278 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-22T18:29:18.278Z,1421951358.278 [SBIT](INFO): Initialize SBIT Component.
2015-01-22T18:29:18.279Z,1421951358.279 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-22T18:29:18.279Z,1421951358.279 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-22T18:29:18.279Z,1421951358.279 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-22T18:29:18.280Z,1421951358.280 [IBIT](INFO): Initialize IBIT Component.
2015-01-22T18:29:18.281Z,1421951358.281 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-22T18:29:18.281Z,1421951358.281 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-01-22T18:29:18.281Z,1421951358.281 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2015-01-22T18:29:18.282Z,1421951358.282 [logger ThreadHandler](INFO): Handler Thread ID is 857
2015-01-22T18:29:18.307Z,1421951358.307 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T18:29:18.307Z,1421951358.307 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-22T18:29:18.308Z,1421951358.308 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-22T18:29:18.308Z,1421951358.308 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-22T18:29:18.308Z,1421951358.308 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-22T18:29:18.309Z,1421951358.309 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2015-01-22T18:29:18.311Z,1421951358.311 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-22T18:29:18.312Z,1421951358.312 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-01-22T18:29:18.312Z,1421951358.312 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-22T18:29:18.312Z,1421951358.312 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-22T18:29:18.318Z,1421951358.318 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-22T18:29:18.330Z,1421951358.330 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 858
2015-01-22T18:29:18.332Z,1421951358.332 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 859
2015-01-22T18:29:18.340Z,1421951358.340 [Radio_Surface](INFO): Powering up
2015-01-22T18:29:18.349Z,1421951358.349 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-22T18:29:18.350Z,1421951358.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-22T18:29:18.350Z,1421951358.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-22T18:29:18.350Z,1421951358.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-22T18:29:18.350Z,1421951358.350 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-22T18:29:18.351Z,1421951358.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-22T18:29:18.351Z,1421951358.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-22T18:29:18.351Z,1421951358.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-22T18:29:18.352Z,1421951358.352 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-22T18:29:18.382Z,1421951358.382 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T18:29:18.396Z,1421951358.396 [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://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.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>


2015-01-22T18:29:18.397Z,1421951358.397 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-22T18:29:18.475Z,1421951358.475 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-22T18:29:18.478Z,1421951358.478 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-22T18:29:18.499Z,1421951358.499 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T18:29:18.523Z,1421951358.523 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-22T18:29:18.538Z,1421951358.538 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-22T18:29:18.590Z,1421951358.590 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-22T18:29:18.605Z,1421951358.605 [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://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="TimeMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <DefineArg Name="ElapsedSinceMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <Aggregate Id="StartClock">

        <Sequence/>

        <Assign><Arg Name="TimeMissionWasStarted"/><Universal:time/></Assign>

    </Aggregate>

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

    <Aggregate Id="CheckIn">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

<!-- TODO: Do we really want this When operating on platform_communications? or on something else like time_fix? -->

<!-- Run application at high speed -->

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
<!-- NOTE: Original Default.xml didn't have a timeout on the GPS read, so theoretically could have hung indefinitely there... -->
            <Universal:latitude_fix/>
        </ReadDatum>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="UpdateAndReportMinutesSinceMissionStarted">

        <When>
            <Elapsed><Arg Name="ElapsedSinceMissionWasStarted"/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
        </When>

        <Assign><Arg Name="ElapsedSinceMissionWasStarted"/><Universal:time/><Sub><Arg Name="TimeMissionWasStarted"/></Sub></Assign>

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

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

        <Guidance:SetSpeed Id="RunApplicationAtLowSpeed">
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
        </Guidance:SetSpeed>

    </Aggregate>

</Mission>


2015-01-22T18:29:18.613Z,1421951358.613 [controlThread](DEBUG): Component order: CycleStarter,AHRS_sp3003D,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRCMReconstructedInterpolator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-01-22T18:29:18.846Z,1421951358.846 [NAL9602](INFO): Start
2015-01-22T18:29:18.847Z,1421951358.847 [NAL9602](INFO): Powering up NAL9602
2015-01-22T18:29:19.220Z,1421951359.220 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:19.235Z,1421951359.235 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-22T18:29:19.493Z,1421951359.493 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-22T18:29:19.501Z,1421951359.501 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-22T18:29:19.507Z,1421951359.507 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-22T18:29:19.513Z,1421951359.513 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-22T18:29:19.535Z,1421951359.535 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-22T18:29:19.541Z,1421951359.541 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-22T18:29:19.559Z,1421951359.559 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-22T18:29:19.565Z,1421951359.565 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-22T18:29:19.602Z,1421951359.602 [CommandLine](FAULT): Scheduling is paused
2015-01-22T18:29:19.989Z,1421951359.989 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:19.998Z,1421951359.998 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-22T18:29:20.338Z,1421951360.338 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2015-01-22T18:29:20.338Z,1421951360.338 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2015-01-22T18:29:20.338Z,1421951360.338 [BuoyancyServo] Communications Fault, FailCount= 1
2015-01-22T18:29:20.338Z,1421951360.338 [BuoyancyServo](ERROR): Communications Fault
2015-01-22T18:29:20.581Z,1421951360.581 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2015-01-22T18:29:29.282Z,1421951369.282 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:29.283Z,1421951369.283 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-22T18:29:29.302Z,1421951369.302 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-22T18:29:29.303Z,1421951369.303 [BuoyancyServo](INFO): Powering down
2015-01-22T18:29:29.467Z,1421951369.467 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:29.467Z,1421951369.467 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-22T18:29:29.818Z,1421951369.818 [NAL9602](INFO): ************** CMDMODE **************

2015-01-22T18:29:29.819Z,1421951369.819 [NAL9602](INFO): NAL9602 initialized
2015-01-22T18:29:29.855Z,1421951369.855 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:29.856Z,1421951369.856 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-22T18:29:30.215Z,1421951370.215 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003806
2015-01-22T18:29:30.275Z,1421951370.275 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:30.276Z,1421951370.276 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-22T18:29:30.664Z,1421951370.664 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:31.073Z,1421951371.073 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:31.514Z,1421951371.514 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:31.557Z,1421951371.557 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2015-01-22T18:29:31.557Z,1421951371.557 [BuoyancyServo] No Fault, FailCount= 1
2015-01-22T18:29:31.927Z,1421951371.927 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:31.951Z,1421951371.951 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-22T18:29:32.069Z,1421951372.069 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-22T18:29:32.267Z,1421951372.267 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:32.720Z,1421951372.720 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:33.025Z,1421951373.025 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:33.465Z,1421951373.465 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:33.914Z,1421951373.914 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:33.935Z,1421951373.935 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-22T18:29:33.937Z,1421951373.937 [CBIT](IMPORTANT): Beginning GF scan
2015-01-22T18:29:34.242Z,1421951374.242 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:34.646Z,1421951374.646 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:35.043Z,1421951375.043 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:35.440Z,1421951375.440 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:35.848Z,1421951375.848 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:36.229Z,1421951376.229 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:36.626Z,1421951376.626 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:37.074Z,1421951377.074 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:37.446Z,1421951377.446 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:37.852Z,1421951377.852 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:38.240Z,1421951378.240 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:38.646Z,1421951378.646 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:39.074Z,1421951379.074 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:39.435Z,1421951379.435 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:39.868Z,1421951379.868 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:40.236Z,1421951380.236 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:40.715Z,1421951380.715 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:41.087Z,1421951381.087 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:41.504Z,1421951381.504 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:41.904Z,1421951381.904 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:42.262Z,1421951382.262 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:42.668Z,1421951382.668 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:43.084Z,1421951383.084 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:43.448Z,1421951383.448 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:43.845Z,1421951383.845 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:44.274Z,1421951384.274 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:44.651Z,1421951384.651 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:45.055Z,1421951385.055 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:45.439Z,1421951385.439 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:45.857Z,1421951385.857 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:46.286Z,1421951386.286 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:46.629Z,1421951386.629 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:47.074Z,1421951387.074 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:47.158Z,1421951387.158 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T18:29:47.447Z,1421951387.447 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:47.886Z,1421951387.886 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:48.272Z,1421951388.272 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:48.644Z,1421951388.644 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:49.041Z,1421951389.041 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:49.449Z,1421951389.449 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:49.843Z,1421951389.843 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:50.231Z,1421951390.231 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:50.648Z,1421951390.648 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:51.032Z,1421951391.032 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:51.441Z,1421951391.441 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:51.845Z,1421951391.845 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:52.234Z,1421951392.234 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:52.643Z,1421951392.643 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:53.047Z,1421951393.047 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:53.439Z,1421951393.439 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:53.860Z,1421951393.860 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:54.245Z,1421951394.245 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:54.654Z,1421951394.654 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:55.034Z,1421951395.034 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:55.447Z,1421951395.447 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:55.848Z,1421951395.848 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:56.240Z,1421951396.240 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:56.645Z,1421951396.645 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:57.049Z,1421951397.049 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:57.472Z,1421951397.472 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:57.847Z,1421951397.847 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:58.244Z,1421951398.244 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:58.695Z,1421951398.695 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:59.057Z,1421951399.057 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:59.442Z,1421951399.442 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:29:59.873Z,1421951399.873 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:00.295Z,1421951400.295 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:00.452Z,1421951400.452 [CBIT](IMPORTANT): No ground fault detected
2015-01-22T18:30:00.684Z,1421951400.684 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:01.093Z,1421951401.093 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:01.441Z,1421951401.441 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:01.866Z,1421951401.866 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:02.241Z,1421951402.241 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:02.675Z,1421951402.675 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:03.043Z,1421951403.043 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:03.460Z,1421951403.460 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:03.538Z,1421951403.538 [CommandLine](IMPORTANT): got command restart system
2015-01-22T18:30:03.844Z,1421951403.844 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:04.253Z,1421951404.253 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:04.660Z,1421951404.660 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:05.059Z,1421951405.059 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:05.435Z,1421951405.435 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:05.832Z,1421951405.832 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:06.232Z,1421951406.232 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:06.633Z,1421951406.633 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:07.033Z,1421951407.033 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:07.434Z,1421951407.434 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:07.835Z,1421951407.835 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:08.234Z,1421951408.234 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:08.636Z,1421951408.636 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:09.028Z,1421951409.028 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:09.487Z,1421951409.487 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:09.846Z,1421951409.846 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:10.250Z,1421951410.250 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:10.635Z,1421951410.635 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:11.036Z,1421951411.036 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:11.436Z,1421951411.436 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:11.828Z,1421951411.828 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:12.229Z,1421951412.229 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:12.630Z,1421951412.630 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:13.026Z,1421951413.026 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:13.431Z,1421951413.431 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:13.567Z,1421951413.567 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T18:30:13.567Z,1421951413.567 [SBIT](FAULT): Control surface position failure.
2015-01-22T18:30:13.832Z,1421951413.832 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:14.256Z,1421951414.256 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:14.654Z,1421951414.654 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5E%57
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,0000%33
$B12,0A,FFFC%35
$B13,0A,FFFC%34
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,0000%3A
$S,01,270F,02,00,04,5E%57
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B91,09,3C3D,0A,0000,0B,0000%3A
$B11,0C,0001,0D,0064,0E,005B,0F,15DF,10,1641,11,FFFF,12,FFFF%34
$B11,13,FFFF,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%4F
$B11,1A,0031,1B,4357,1C,009D%49
$B12,02,000A,01,026C,03,0001,08,0B95,09,3D21,0A,FFFC,0B,FFFC%4E
$B12,0C,0001,0D,0055,0E,0053,0F,140F,10,17B2,11,FFFF,12,FFFF%45
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,0093%3D
$B13,02,000A,01,026C,03,0001,08,0B9E,09,3D20,0A,FFFC,0B,FFFC%3E
$B13,0C,0001,0D,005F,0E,0051,0F,1368,10,16D7,11,FFFF,12,FFFF%48
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4333,1C,0068%3A
$B14,02,000A,01,026C,03,0001,08,0B94,09,3D20,0A,FFFC,0B,FFFC%48
$B14,0C,0001,0D,0055,0E,004F,0F,1310,10,168C,11,FFFF,12,FFFF%4D
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,008D%4D
$B15,02,000A,01,026C,03,0001,08,0B98,09,3C29,0A,0000,0B,0000%4B
$B15,0C,0001,0D,0064,0E,005B,0F,15FF,10,16B6,11,FFFF,12,FFFF%43
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,008A%49
$B16,02,000A,01,026C,03,0001,08,0B92,09,3C32,0A,0000,0B,0000%48
$B16,0C,0001,0D,0064,0E,005E,0F,16AB,10,16AB,11,FFFF,12,FFFF%30
$B16,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4B
$B16,1A,0031,1B,4357,1C,00B9%48
$B17,02,000A,01,026C,03,0001,08,0B94,09,3C2C,0A,0000,0B,0000%3F
$B17,0C,0001,0D,0064,0E,005F,0F,16D3,10,1701,11,FFFF,12,FFFF%45
$B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B17,1A,0031,1B,4357,1C,00A5%46
$B18,02,000A,01,026C,03,0001,08,0B98,09,3D17,0A,0000,0B,0000%4C
$B18,0C,0001,0D,005B,0E,0053,0F,1411,10,16AD,11,FFFF,12,FFFF%3A
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,00AE%39

2015-01-22T18:30:14.667Z,1421951414.667 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T18:30:14.667Z,1421951414.667 [BPC1] Data Fault, FailCount= 1
2015-01-22T18:30:14.667Z,1421951414.667 [BPC1](ERROR): Data Fault
2015-01-22T18:30:14.685Z,1421951414.685 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:14.758Z,1421951414.758 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T18:30:15.030Z,1421951415.030 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T18:30:15.031Z,1421951415.031 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:15.046Z,1421951415.046 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:15.091Z,1421951415.091 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-22T18:30:15.091Z,1421951415.091 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:15.092Z,1421951415.092 [CommandLine](INFO): Join timeout helper Thread ID is 882
2015-01-22T18:30:15.108Z,1421951415.108 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-22T18:30:15.109Z,1421951415.109 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:15.109Z,1421951415.109 [NavChartDb](INFO): Join timeout helper Thread ID is 883
2015-01-22T18:30:15.471Z,1421951415.471 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:15.850Z,1421951415.850 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:15.940Z,1421951415.940 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T18:30:15.940Z,1421951415.940 [BPC1] No Fault, FailCount= 1
2015-01-22T18:30:16.324Z,1421951416.324 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:16.447Z,1421951416.447 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T18:30:16.447Z,1421951416.447 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.449Z,1421951416.449 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-22T18:30:16.449Z,1421951416.449 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.450Z,1421951416.450 [Radio_Surface](INFO): Join timeout helper Thread ID is 884
2015-01-22T18:30:16.554Z,1421951416.554 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T18:30:16.554Z,1421951416.554 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.569Z,1421951416.569 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-22T18:30:16.570Z,1421951416.570 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.570Z,1421951416.570 [logger](INFO): Join timeout helper Thread ID is 885
2015-01-22T18:30:16.618Z,1421951416.618 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T18:30:16.618Z,1421951416.618 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.625Z,1421951416.625 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-01-22T18:30:16.630Z,1421951416.630 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-22T18:30:16.630Z,1421951416.630 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.630Z,1421951416.630 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-22T18:30:16.630Z,1421951416.630 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.630Z,1421951416.630 [controlThread](INFO): Join timeout helper Thread ID is 886
2015-01-22T18:30:16.690Z,1421951416.690 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T18:30:16.691Z,1421951416.691 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-22T18:30:16.691Z,1421951416.691 [NAL9602](INFO): Uninitialize
2015-01-22T18:30:16.691Z,1421951416.691 [NAL9602](INFO): Powering down
2015-01-22T18:30:16.693Z,1421951416.693 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T18:30:16.695Z,1421951416.695 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-22T18:30:16.699Z,1421951416.699 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-22T18:30:16.700Z,1421951416.700 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-22T18:30:16.700Z,1421951416.700 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-22T18:30:16.700Z,1421951416.700 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-22T18:30:16.701Z,1421951416.701 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-22T18:30:16.701Z,1421951416.701 [BuoyancyServo](INFO): Powering down
2015-01-22T18:30:16.714Z,1421951416.714 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-22T18:30:16.714Z,1421951416.714 [ElevatorServo](INFO): Powering down
2015-01-22T18:30:16.715Z,1421951416.715 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-22T18:30:16.715Z,1421951416.715 [RudderServo](INFO): Powering down
2015-01-22T18:30:16.716Z,1421951416.716 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-22T18:30:16.716Z,1421951416.716 [ThrusterServo](INFO): Powering down
2015-01-22T18:30:16.717Z,1421951416.717 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-22T18:30:16.717Z,1421951416.717 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-22T18:30:16.717Z,1421951416.717 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-22T18:30:16.750Z,1421951416.750 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:16.855Z,1421951416.855 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:17.135Z,1421951417.135 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T18:30:17.184Z,1421951417.184 [logger ThreadHandler](INFO): Thread cancelled.