2015-02-17T18:47:11.446Z,1424198831.446 [Supervisor](DEBUG): Initializing supervisor.
2015-02-17T18:47:11.450Z,1424198831.450 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-02-17T18:47:11.450Z,1424198831.450 [SyncHandler](INFO): Protected caller Thread ID is 775
2015-02-17T18:47:11.451Z,1424198831.451 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-02-17T18:47:11.455Z,1424198831.455 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-02-17T18:47:11.456Z,1424198831.456 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 776
2015-02-17T18:47:11.458Z,1424198831.458 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-02-17T18:47:11.470Z,1424198831.470 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-02-17T18:47:11.475Z,1424198831.475 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-02-17T18:47:11.476Z,1424198831.476 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 777
2015-02-17T18:47:11.476Z,1424198831.476 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-02-17T18:47:11.479Z,1424198831.479 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-02-17T18:47:11.480Z,1424198831.480 [logger ThreadHandler](INFO): Protected caller Thread ID is 778
2015-02-17T18:47:11.482Z,1424198831.482 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-02-17T18:47:11.482Z,1424198831.482 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-02-17T18:47:11.488Z,1424198831.488 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-02-17T18:47:11.888Z,1424198831.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-02-17T18:47:11.889Z,1424198831.889 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-02-17T18:47:12.081Z,1424198832.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-02-17T18:47:12.082Z,1424198832.082 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-02-17T18:47:12.216Z,1424198832.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-02-17T18:47:12.217Z,1424198832.217 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-02-17T18:47:12.366Z,1424198832.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-02-17T18:47:12.366Z,1424198832.366 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-02-17T18:47:12.465Z,1424198832.465 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-02-17T18:47:12.661Z,1424198832.661 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-02-17T18:47:12.662Z,1424198832.662 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-02-17T18:47:12.765Z,1424198832.765 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-02-17T18:47:12.768Z,1424198832.768 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-02-17T18:47:13.017Z,1424198833.017 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-02-17T18:47:13.018Z,1424198833.018 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-02-17T18:47:13.447Z,1424198833.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-02-17T18:47:13.448Z,1424198833.448 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-02-17T18:47:13.828Z,1424198833.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-02-17T18:47:13.828Z,1424198833.828 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-02-17T18:47:14.422Z,1424198834.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-02-17T18:47:14.422Z,1424198834.422 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-02-17T18:47:14.710Z,1424198834.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-02-17T18:47:14.710Z,1424198834.710 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-02-17T18:47:14.835Z,1424198834.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-02-17T18:47:14.836Z,1424198834.836 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-02-17T18:47:15.367Z,1424198835.367 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-02-17T18:47:15.368Z,1424198835.368 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-02-17T18:47:26.777Z,1424198846.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-02-17T18:47:26.778Z,1424198846.778 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-02-17T18:47:26.863Z,1424198846.863 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-02-17T18:47:27.118Z,1424198847.118 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-02-17T18:47:27.119Z,1424198847.119 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-02-17T18:47:28.027Z,1424198848.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-02-17T18:47:28.240Z,1424198848.240 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-02-17T18:47:28.420Z,1424198848.420 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-02-17T18:47:28.639Z,1424198848.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-02-17T18:47:29.034Z,1424198849.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-02-17T18:47:29.468Z,1424198849.468 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-02-17T18:47:29.746Z,1424198849.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-02-17T18:47:29.943Z,1424198849.943 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-02-17T18:47:30.139Z,1424198850.139 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-02-17T18:47:30.356Z,1424198850.356 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-02-17T18:47:30.831Z,1424198850.831 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2015-02-17T18:47:30.831Z,1424198850.831 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-02-17T18:47:30.855Z,1424198850.855 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-02-17T18:47:31.018Z,1424198851.018 [VerticalControl](DEBUG): Construct VerticalControl.
2015-02-17T18:47:31.334Z,1424198851.334 [VerticalControl] Loaded
2015-02-17T18:47:31.335Z,1424198851.335 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-02-17T18:47:31.335Z,1424198851.335 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-02-17T18:47:31.524Z,1424198851.524 [HorizontalControl] Loaded
2015-02-17T18:47:31.524Z,1424198851.524 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-02-17T18:47:31.525Z,1424198851.525 [SpeedControl](DEBUG): Construct SpeedControl.
2015-02-17T18:47:31.531Z,1424198851.531 [SpeedControl] Loaded
2015-02-17T18:47:31.531Z,1424198851.531 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-02-17T18:47:31.532Z,1424198851.532 [LoopControl](DEBUG): Construct LoopControl.
2015-02-17T18:47:31.533Z,1424198851.533 [LoopControl] Loaded
2015-02-17T18:47:31.533Z,1424198851.533 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-02-17T18:47:31.534Z,1424198851.534 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-02-17T18:47:31.534Z,1424198851.534 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-02-17T18:47:41.403Z,1424198861.403 [SBIT](DEBUG): Construct Startup Built In Test.
2015-02-17T18:47:41.415Z,1424198861.415 [SBIT] Loaded
2015-02-17T18:47:41.415Z,1424198861.415 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-02-17T18:47:41.416Z,1424198861.416 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-02-17T18:47:41.446Z,1424198861.446 [IBIT] Loaded
2015-02-17T18:47:41.446Z,1424198861.446 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-02-17T18:47:41.448Z,1424198861.448 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-02-17T18:47:41.587Z,1424198861.587 [CBIT] Loaded
2015-02-17T18:47:41.587Z,1424198861.587 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-02-17T18:47:41.587Z,1424198861.587 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-02-17T18:47:41.588Z,1424198861.588 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-02-17T18:47:45.264Z,1424198865.264 [DepthRateCalculator] Loaded
2015-02-17T18:47:45.264Z,1424198865.264 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-02-17T18:47:45.271Z,1424198865.271 [PitchRateCalculator] Loaded
2015-02-17T18:47:45.271Z,1424198865.271 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-02-17T18:47:45.295Z,1424198865.295 [SpeedCalculator] Loaded
2015-02-17T18:47:45.296Z,1424198865.296 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-02-17T18:47:45.347Z,1424198865.347 [TempGradientCalculator] Loaded
2015-02-17T18:47:45.348Z,1424198865.348 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-02-17T18:47:45.353Z,1424198865.353 [YawRateCalculator] Loaded
2015-02-17T18:47:45.354Z,1424198865.354 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-02-17T18:47:45.354Z,1424198865.354 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-02-17T18:47:45.355Z,1424198865.355 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-02-17T18:47:46.919Z,1424198866.919 [HFRCMReconstructedInterpolator] Loaded
2015-02-17T18:47:46.920Z,1424198866.920 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2015-02-17T18:47:46.920Z,1424198866.920 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-02-17T18:47:46.921Z,1424198866.921 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-02-17T18:47:47.212Z,1424198867.212 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-02-17T18:47:47.213Z,1424198867.213 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-02-17T18:47:47.324Z,1424198867.324 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-02-17T18:47:47.325Z,1424198867.325 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-02-17T18:47:47.373Z,1424198867.373 [DeadReckonUsingSpeedCalculator] Loaded
2015-02-17T18:47:47.374Z,1424198867.374 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-02-17T18:47:47.422Z,1424198867.422 [DeadReckonWithRespectToWater] Loaded
2015-02-17T18:47:47.422Z,1424198867.422 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2015-02-17T18:47:47.440Z,1424198867.440 [NavChart] Loaded
2015-02-17T18:47:47.441Z,1424198867.441 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-02-17T18:47:47.445Z,1424198867.445 [UniversalFixResidualReporter] Loaded
2015-02-17T18:47:47.445Z,1424198867.445 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-02-17T18:47:47.446Z,1424198867.446 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-02-17T18:47:47.447Z,1424198867.447 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-02-17T18:47:47.456Z,1424198867.456 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-02-17T18:47:47.457Z,1424198867.457 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-02-17T18:47:47.584Z,1424198867.584 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-02-17T18:47:47.585Z,1424198867.585 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-02-17T18:47:48.248Z,1424198868.248 [DataOverHttps] Loaded
2015-02-17T18:47:48.249Z,1424198868.249 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-02-17T18:47:48.333Z,1424198868.333 [Depth_Keller] Loaded
2015-02-17T18:47:48.333Z,1424198868.333 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-02-17T18:47:48.432Z,1424198868.432 [NAL9602] Loaded
2015-02-17T18:47:48.433Z,1424198868.433 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-02-17T18:47:48.478Z,1424198868.478 [Onboard] Loaded
2015-02-17T18:47:48.478Z,1424198868.478 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-02-17T18:47:48.486Z,1424198868.486 [Radio_Surface] Loaded
2015-02-17T18:47:48.486Z,1424198868.486 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-02-17T18:47:48.488Z,1424198868.488 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408074E0
2015-02-17T18:47:48.488Z,1424198868.488 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 867
2015-02-17T18:47:50.436Z,1424198870.436 [BPC1] Loaded
2015-02-17T18:47:50.437Z,1424198870.437 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-02-17T18:47:50.437Z,1424198870.437 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-02-17T18:47:50.438Z,1424198870.438 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-02-17T18:47:50.584Z,1424198870.584 [BuoyancyServo] Loaded
2015-02-17T18:47:50.584Z,1424198870.584 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-02-17T18:47:50.597Z,1424198870.597 [ElevatorServo] Loaded
2015-02-17T18:47:50.597Z,1424198870.597 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-02-17T18:47:50.610Z,1424198870.610 [MassServo] Loaded
2015-02-17T18:47:50.610Z,1424198870.610 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-02-17T18:47:50.623Z,1424198870.623 [RudderServo] Loaded
2015-02-17T18:47:50.624Z,1424198870.624 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-02-17T18:47:50.636Z,1424198870.636 [ThrusterServo] Loaded
2015-02-17T18:47:50.636Z,1424198870.636 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-02-17T18:47:50.637Z,1424198870.637 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-02-17T18:47:50.638Z,1424198870.638 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-02-17T18:47:50.927Z,1424198870.927 [ExternalSim] Loaded
2015-02-17T18:47:50.927Z,1424198870.927 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2015-02-17T18:47:50.928Z,1424198870.928 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-02-17T18:47:50.929Z,1424198870.929 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-02-17T18:47:50.970Z,1424198870.970 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-02-17T18:47:50.972Z,1424198870.972 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-02-17T18:47:50.973Z,1424198870.973 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-02-17T18:47:50.980Z,1424198870.980 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-02-17T18:47:50.981Z,1424198870.981 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408B84E0
2015-02-17T18:47:50.981Z,1424198870.981 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 868
2015-02-17T18:47:50.986Z,1424198870.986 [Supervisor](INFO): Main Thread ID is 772
2015-02-17T18:47:50.986Z,1424198870.986 [Supervisor](DEBUG): Running supervisor.
2015-02-17T18:47:50.987Z,1424198870.987 [CommandLine ThreadHandler](INFO): Handler Thread ID is 869
2015-02-17T18:47:50.998Z,1424198870.998 [controlThread ThreadHandler](INFO): Handler Thread ID is 870
2015-02-17T18:47:50.998Z,1424198870.998 [controlThread](DEBUG): Initializing ControlThread
2015-02-17T18:47:50.999Z,1424198870.999 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-02-17T18:47:51.001Z,1424198871.001 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-02-17T18:47:51.002Z,1424198871.002 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-02-17T18:47:51.002Z,1424198871.002 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-02-17T18:47:51.002Z,1424198871.002 [SBIT](INFO): Initialize SBIT Component.
2015-02-17T18:47:51.003Z,1424198871.003 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12012
2015-02-17T18:47:51.003Z,1424198871.003 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-02-17T18:47:51.003Z,1424198871.003 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-02-17T18:47:51.004Z,1424198871.004 [IBIT](INFO): Initialize IBIT Component.
2015-02-17T18:47:51.005Z,1424198871.005 [CBIT](DEBUG): Initialize CBIT Component.
2015-02-17T18:47:51.006Z,1424198871.006 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-02-17T18:47:51.006Z,1424198871.006 [logger ThreadHandler](INFO): Handler Thread ID is 871
2015-02-17T18:47:51.025Z,1424198871.025 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 872
2015-02-17T18:47:51.029Z,1424198871.029 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-02-17T18:47:51.029Z,1424198871.029 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-02-17T18:47:51.030Z,1424198871.030 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-02-17T18:47:51.030Z,1424198871.030 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-02-17T18:47:51.030Z,1424198871.030 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-02-17T18:47:51.031Z,1424198871.031 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2015-02-17T18:47:51.033Z,1424198871.033 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-02-17T18:47:51.034Z,1424198871.034 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-02-17T18:47:51.034Z,1424198871.034 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2015-02-17T18:47:51.034Z,1424198871.034 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-02-17T18:47:51.035Z,1424198871.035 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-02-17T18:47:51.039Z,1424198871.039 [ExternalSim](INFO): ExternalSim initializing...
2015-02-17T18:47:51.049Z,1424198871.049 [Radio_Surface](INFO): Powering up
2015-02-17T18:47:51.062Z,1424198871.062 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 873
2015-02-17T18:47:51.075Z,1424198871.075 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-02-17T18:47:51.076Z,1424198871.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-02-17T18:47:51.076Z,1424198871.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-02-17T18:47:51.076Z,1424198871.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-02-17T18:47:51.076Z,1424198871.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-02-17T18:47:51.077Z,1424198871.077 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-02-17T18:47:51.077Z,1424198871.077 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-02-17T18:47:51.077Z,1424198871.077 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-02-17T18:47:51.078Z,1424198871.078 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-02-17T18:47:51.340Z,1424198871.340 [ExternalSim](DEBUG): beaconLat = 36.80340
2015-02-17T18:47:51.340Z,1424198871.340 [ExternalSim](DEBUG): beaconLon = -121.82230
2015-02-17T18:47:51.340Z,1424198871.340 [ExternalSim](DEBUG): beaconDepth = 25.00
2015-02-17T18:47:51.789Z,1424198871.789 [ExternalSim](DEBUG): Simulator initialized
2015-02-17T18:47:51.907Z,1424198871.907 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-02-17T18:47:51.947Z,1424198871.947 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-02-17T18:47:51.956Z,1424198871.956 [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-02-17T18:47:51.957Z,1424198871.957 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-02-17T18:47:52.039Z,1424198872.039 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-02-17T18:47:52.059Z,1424198872.059 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-02-17T18:47:52.063Z,1424198872.063 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-02-17T18:47:52.082Z,1424198872.082 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-02-17T18:47:52.120Z,1424198872.120 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-02-17T18:47:52.144Z,1424198872.144 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-02-17T18:47:52.166Z,1424198872.166 [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-02-17T18:47:52.172Z,1424198872.172 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRCMReconstructedInterpolator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToWater,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-02-17T18:47:52.800Z,1424198872.800 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:47:52.814Z,1424198872.814 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:47:52.980Z,1424198872.980 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:47:52.988Z,1424198872.988 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-02-17T18:47:53.015Z,1424198873.015 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:47:53.024Z,1424198873.024 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-02-17T18:47:53.030Z,1424198873.030 [MassServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:47:53.036Z,1424198873.036 [MassServo](DEBUG): Initializing MassServo.
2015-02-17T18:47:53.058Z,1424198873.058 [RudderServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:47:53.064Z,1424198873.064 [RudderServo](DEBUG): Initializing RudderServo.
2015-02-17T18:47:53.071Z,1424198873.071 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:47:53.076Z,1424198873.076 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-02-17T18:47:53.320Z,1424198873.320 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:47:53.321Z,1424198873.321 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:48:02.292Z,1424198882.292 [NAL9602](INFO): Powering up NAL9602
2015-02-17T18:48:02.369Z,1424198882.369 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:02.370Z,1424198882.370 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:48:02.805Z,1424198882.805 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:02.806Z,1424198882.806 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:48:03.268Z,1424198883.268 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:03.269Z,1424198883.269 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:48:03.591Z,1424198883.591 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003506
2015-02-17T18:48:03.631Z,1424198883.631 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:03.632Z,1424198883.632 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:48:04.010Z,1424198884.010 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:04.411Z,1424198884.411 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:04.816Z,1424198884.816 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:05.193Z,1424198885.193 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:05.792Z,1424198885.792 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:06.176Z,1424198886.176 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:06.275Z,1424198886.275 [SBIT](IMPORTANT): Beginning Startup BIT
2015-02-17T18:48:06.277Z,1424198886.277 [CBIT](IMPORTANT): Beginning GF scan
2015-02-17T18:48:06.596Z,1424198886.596 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:07.245Z,1424198887.245 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:07.649Z,1424198887.649 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:08.026Z,1424198888.026 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:08.462Z,1424198888.462 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:08.848Z,1424198888.848 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:09.253Z,1424198889.253 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:09.672Z,1424198889.672 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:10.112Z,1424198890.112 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:10.662Z,1424198890.662 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:10.882Z,1424198890.882 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:11.306Z,1424198891.306 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:11.904Z,1424198891.904 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:12.128Z,1424198892.128 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:12.775Z,1424198892.775 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:13.122Z,1424198893.122 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:13.481Z,1424198893.481 [NAL9602](INFO): NAL9602 initialized
2015-02-17T18:48:13.518Z,1424198893.518 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:13.923Z,1424198893.923 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:14.388Z,1424198894.388 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:14.732Z,1424198894.732 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:15.105Z,1424198895.105 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:15.530Z,1424198895.530 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:15.906Z,1424198895.906 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:16.359Z,1424198896.359 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:16.752Z,1424198896.752 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:17.097Z,1424198897.097 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:48:17.098Z,1424198897.098 [NAL9602](INFO): Response:
+CSQ:0

OK
2015-02-17T18:48:17.112Z,1424198897.112 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:17.528Z,1424198897.528 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:17.873Z,1424198897.873 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:18.302Z,1424198898.302 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:18.674Z,1424198898.674 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:19.095Z,1424198899.095 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:19.518Z,1424198899.518 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:19.632Z,1424198899.632 [SBIT](FAULT): Mass: EXPECTED:0.006000 ACTUAL:0.004808
2015-02-17T18:48:19.896Z,1424198899.896 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:20.297Z,1424198900.297 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:20.694Z,1424198900.694 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:21.074Z,1424198901.074 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:21.504Z,1424198901.504 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:48:21.504Z,1424198901.504 [NAL9602](INFO): Response:
+CSQ:0

OK
2015-02-17T18:48:21.519Z,1424198901.519 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:21.887Z,1424198901.887 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:22.272Z,1424198902.272 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:22.480Z,1424198902.480 [CommandLine](IMPORTANT): got command quit
2015-02-17T18:48:22.676Z,1424198902.676 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:23.107Z,1424198903.107 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:48:23.107Z,1424198903.107 [NAL9602](INFO): Response:
+CSQ:0

OK
2015-02-17T18:48:23.129Z,1424198903.129 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:23.594Z,1424198903.594 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:23.910Z,1424198903.910 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:24.271Z,1424198904.271 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:24.684Z,1424198904.684 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:25.132Z,1424198905.132 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:25.497Z,1424198905.497 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:25.882Z,1424198905.882 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:26.307Z,1424198906.307 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:26.704Z,1424198906.704 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:27.100Z,1424198907.100 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:27.502Z,1424198907.502 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:27.873Z,1424198907.873 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:28.298Z,1424198908.298 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:28.675Z,1424198908.675 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:29.143Z,1424198909.143 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:29.496Z,1424198909.496 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:29.928Z,1424198909.928 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:30.276Z,1424198910.276 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:30.749Z,1424198910.749 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:31.154Z,1424198911.154 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:31.504Z,1424198911.504 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:48:31.504Z,1424198911.504 [NAL9602](INFO): Response:
+CSQ:0

OK
2015-02-17T18:48:31.518Z,1424198911.518 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:31.906Z,1424198911.906 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:32.276Z,1424198912.276 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:32.354Z,1424198912.354 [CBIT](IMPORTANT): No ground fault detected
2015-02-17T18:48:32.676Z,1424198912.676 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:33.078Z,1424198913.078 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:33.474Z,1424198913.474 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:33.890Z,1424198913.890 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:33.902Z,1424198913.902 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:48:33.903Z,1424198913.903 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:33.995Z,1424198913.995 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-02-17T18:48:33.996Z,1424198913.996 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:33.996Z,1424198913.996 [CommandLine](INFO): Join timeout helper Thread ID is 890
2015-02-17T18:48:33.997Z,1424198913.997 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-02-17T18:48:33.997Z,1424198913.997 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:33.997Z,1424198913.997 [NavChartDb](INFO): Join timeout helper Thread ID is 891
2015-02-17T18:48:34.403Z,1424198914.403 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:34.694Z,1424198914.694 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:35.092Z,1424198915.092 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:35.493Z,1424198915.493 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:35.895Z,1424198915.895 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:48:35.895Z,1424198915.895 [NAL9602](INFO): Response:
+CSQ:0

OK
2015-02-17T18:48:35.925Z,1424198915.925 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:36.342Z,1424198916.342 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:36.702Z,1424198916.702 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:37.131Z,1424198917.131 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:37.517Z,1424198917.517 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:37.896Z,1424198917.896 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:48:37.896Z,1424198917.896 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:37.910Z,1424198917.910 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-02-17T18:48:37.910Z,1424198917.910 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:37.910Z,1424198917.910 [Radio_Surface](INFO): Join timeout helper Thread ID is 892
2015-02-17T18:48:37.925Z,1424198917.925 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:48:37.954Z,1424198917.954 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:48:37.954Z,1424198917.954 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:37.966Z,1424198917.966 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-02-17T18:48:37.966Z,1424198917.966 [logger ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:37.966Z,1424198917.966 [logger](INFO): Join timeout helper Thread ID is 893
2015-02-17T18:48:37.983Z,1424198917.983 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:48:37.983Z,1424198917.983 [logger ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:37.986Z,1424198917.986 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-02-17T18:48:37.986Z,1424198917.986 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:37.986Z,1424198917.986 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-02-17T18:48:37.986Z,1424198917.986 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:37.987Z,1424198917.987 [controlThread](INFO): Join timeout helper Thread ID is 894
2015-02-17T18:48:38.055Z,1424198918.055 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:48:38.056Z,1424198918.056 [controlThread](DEBUG): Uninitializing ControlThread
2015-02-17T18:48:38.057Z,1424198918.057 [NAL9602](INFO): Powering down
2015-02-17T18:48:38.059Z,1424198918.059 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-02-17T18:48:38.061Z,1424198918.061 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-02-17T18:48:38.065Z,1424198918.065 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-02-17T18:48:38.065Z,1424198918.065 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-02-17T18:48:38.066Z,1424198918.066 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-02-17T18:48:38.066Z,1424198918.066 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-02-17T18:48:38.066Z,1424198918.066 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-02-17T18:48:38.067Z,1424198918.067 [BuoyancyServo](INFO): Powering down
2015-02-17T18:48:38.078Z,1424198918.078 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-02-17T18:48:38.078Z,1424198918.078 [ElevatorServo](INFO): Powering down
2015-02-17T18:48:38.079Z,1424198918.079 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-02-17T18:48:38.079Z,1424198918.079 [MassServo](INFO): Powering down
2015-02-17T18:48:38.080Z,1424198918.080 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-02-17T18:48:38.080Z,1424198918.080 [RudderServo](INFO): Powering down
2015-02-17T18:48:38.081Z,1424198918.081 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-02-17T18:48:38.081Z,1424198918.081 [ThrusterServo](INFO): Powering down
2015-02-17T18:48:38.082Z,1424198918.082 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-02-17T18:48:38.083Z,1424198918.083 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-02-17T18:48:38.083Z,1424198918.083 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-02-17T18:48:38.115Z,1424198918.115 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:38.312Z,1424198918.312 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:38.510Z,1424198918.510 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:48:38.587Z,1424198918.587 [logger ThreadHandler](INFO): Thread cancelled.