2015-02-17T18:18:27.890Z,1424197107.890 [Supervisor](DEBUG): Initializing supervisor.
2015-02-17T18:18:27.901Z,1424197107.901 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-02-17T18:18:27.902Z,1424197107.902 [SyncHandler](INFO): Protected caller Thread ID is 996
2015-02-17T18:18:27.902Z,1424197107.902 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-02-17T18:18:27.913Z,1424197107.913 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-02-17T18:18:27.914Z,1424197107.914 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 997
2015-02-17T18:18:27.916Z,1424197107.916 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-02-17T18:18:27.939Z,1424197107.939 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-02-17T18:18:27.949Z,1424197107.949 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-02-17T18:18:27.950Z,1424197107.950 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 998
2015-02-17T18:18:27.950Z,1424197107.950 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-02-17T18:18:27.957Z,1424197107.957 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-02-17T18:18:27.958Z,1424197107.958 [logger ThreadHandler](INFO): Protected caller Thread ID is 999
2015-02-17T18:18:27.960Z,1424197107.960 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-02-17T18:18:27.960Z,1424197107.960 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-02-17T18:18:27.962Z,1424197107.962 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-02-17T18:18:28.654Z,1424197108.654 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-02-17T18:18:28.655Z,1424197108.655 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-02-17T18:18:28.880Z,1424197108.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-02-17T18:18:28.881Z,1424197108.881 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-02-17T18:18:28.989Z,1424197108.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-02-17T18:18:28.989Z,1424197108.989 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-02-17T18:18:29.111Z,1424197109.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-02-17T18:18:29.112Z,1424197109.112 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-02-17T18:18:29.197Z,1424197109.197 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-02-17T18:18:29.356Z,1424197109.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-02-17T18:18:29.356Z,1424197109.356 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-02-17T18:18:29.441Z,1424197109.441 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-02-17T18:18:29.442Z,1424197109.442 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-02-17T18:18:29.649Z,1424197109.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-02-17T18:18:29.650Z,1424197109.650 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-02-17T18:18:30.026Z,1424197110.026 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-02-17T18:18:30.026Z,1424197110.026 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-02-17T18:18:30.335Z,1424197110.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-02-17T18:18:30.336Z,1424197110.336 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-02-17T18:18:30.845Z,1424197110.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-02-17T18:18:30.846Z,1424197110.846 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-02-17T18:18:31.092Z,1424197111.092 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-02-17T18:18:31.092Z,1424197111.092 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-02-17T18:18:31.199Z,1424197111.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-02-17T18:18:31.200Z,1424197111.200 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-02-17T18:18:31.633Z,1424197111.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-02-17T18:18:31.634Z,1424197111.634 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-02-17T18:18:31.744Z,1424197111.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-02-17T18:18:31.746Z,1424197111.746 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-02-17T18:18:31.746Z,1424197111.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-02-17T18:18:31.989Z,1424197111.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-02-17T18:18:31.989Z,1424197111.989 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-02-17T18:18:32.105Z,1424197112.105 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-02-17T18:18:32.209Z,1424197112.209 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-02-17T18:18:32.307Z,1424197112.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-02-17T18:18:32.415Z,1424197112.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-02-17T18:18:32.556Z,1424197112.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-02-17T18:18:32.725Z,1424197112.725 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-02-17T18:18:32.828Z,1424197112.828 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-02-17T18:18:32.917Z,1424197112.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-02-17T18:18:33.026Z,1424197113.026 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-02-17T18:18:33.122Z,1424197113.122 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-02-17T18:18:33.303Z,1424197113.303 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2015-02-17T18:18:33.303Z,1424197113.303 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-02-17T18:18:33.316Z,1424197113.316 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-02-17T18:18:33.369Z,1424197113.369 [VerticalControl](DEBUG): Construct VerticalControl.
2015-02-17T18:18:33.490Z,1424197113.490 [VerticalControl] Loaded
2015-02-17T18:18:33.490Z,1424197113.490 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-02-17T18:18:33.491Z,1424197113.491 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-02-17T18:18:33.564Z,1424197113.564 [HorizontalControl] Loaded
2015-02-17T18:18:33.565Z,1424197113.565 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-02-17T18:18:33.565Z,1424197113.565 [SpeedControl](DEBUG): Construct SpeedControl.
2015-02-17T18:18:33.571Z,1424197113.571 [SpeedControl] Loaded
2015-02-17T18:18:33.571Z,1424197113.571 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-02-17T18:18:33.572Z,1424197113.572 [LoopControl](DEBUG): Construct LoopControl.
2015-02-17T18:18:33.573Z,1424197113.573 [LoopControl] Loaded
2015-02-17T18:18:33.573Z,1424197113.573 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-02-17T18:18:33.573Z,1424197113.573 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-02-17T18:18:33.574Z,1424197113.574 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-02-17T18:18:33.676Z,1424197113.676 [SBIT](DEBUG): Construct Startup Built In Test.
2015-02-17T18:18:33.687Z,1424197113.687 [SBIT] Loaded
2015-02-17T18:18:33.688Z,1424197113.688 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-02-17T18:18:33.688Z,1424197113.688 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-02-17T18:18:33.718Z,1424197113.718 [IBIT] Loaded
2015-02-17T18:18:33.718Z,1424197113.718 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-02-17T18:18:33.720Z,1424197113.720 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-02-17T18:18:33.855Z,1424197113.855 [CBIT] Loaded
2015-02-17T18:18:33.856Z,1424197113.856 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-02-17T18:18:33.856Z,1424197113.856 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-02-17T18:18:33.857Z,1424197113.857 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-02-17T18:18:33.876Z,1424197113.876 [DepthRateCalculator] Loaded
2015-02-17T18:18:33.876Z,1424197113.876 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-02-17T18:18:33.882Z,1424197113.882 [PitchRateCalculator] Loaded
2015-02-17T18:18:33.882Z,1424197113.882 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-02-17T18:18:33.894Z,1424197113.894 [SpeedCalculator] Loaded
2015-02-17T18:18:33.894Z,1424197113.894 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-02-17T18:18:33.936Z,1424197113.936 [TempGradientCalculator] Loaded
2015-02-17T18:18:33.937Z,1424197113.937 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-02-17T18:18:33.942Z,1424197113.942 [YawRateCalculator] Loaded
2015-02-17T18:18:33.942Z,1424197113.942 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-02-17T18:18:33.943Z,1424197113.943 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-02-17T18:18:33.943Z,1424197113.943 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-02-17T18:18:34.985Z,1424197114.985 [HFRCMReconstructedInterpolator] Loaded
2015-02-17T18:18:34.985Z,1424197114.985 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2015-02-17T18:18:34.986Z,1424197114.986 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-02-17T18:18:34.986Z,1424197114.986 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-02-17T18:18:35.230Z,1424197115.230 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-02-17T18:18:35.231Z,1424197115.231 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-02-17T18:18:35.318Z,1424197115.318 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-02-17T18:18:35.318Z,1424197115.318 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-02-17T18:18:35.365Z,1424197115.365 [DeadReckonUsingSpeedCalculator] Loaded
2015-02-17T18:18:35.366Z,1424197115.366 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-02-17T18:18:35.413Z,1424197115.413 [DeadReckonWithRespectToWater] Loaded
2015-02-17T18:18:35.413Z,1424197115.413 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2015-02-17T18:18:35.432Z,1424197115.432 [NavChart] Loaded
2015-02-17T18:18:35.432Z,1424197115.432 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-02-17T18:18:35.437Z,1424197115.437 [UniversalFixResidualReporter] Loaded
2015-02-17T18:18:35.437Z,1424197115.437 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-02-17T18:18:35.438Z,1424197115.438 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-02-17T18:18:35.438Z,1424197115.438 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-02-17T18:18:35.444Z,1424197115.444 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-02-17T18:18:35.445Z,1424197115.445 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-02-17T18:18:35.540Z,1424197115.540 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-02-17T18:18:35.541Z,1424197115.541 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-02-17T18:18:35.899Z,1424197115.899 [DataOverHttps] Loaded
2015-02-17T18:18:35.899Z,1424197115.899 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-02-17T18:18:35.981Z,1424197115.981 [Depth_Keller] Loaded
2015-02-17T18:18:35.982Z,1424197115.982 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-02-17T18:18:36.080Z,1424197116.080 [NAL9602] Loaded
2015-02-17T18:18:36.080Z,1424197116.080 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-02-17T18:18:36.124Z,1424197116.124 [Onboard] Loaded
2015-02-17T18:18:36.124Z,1424197116.124 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-02-17T18:18:36.131Z,1424197116.131 [Radio_Surface] Loaded
2015-02-17T18:18:36.132Z,1424197116.132 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-02-17T18:18:36.133Z,1424197116.133 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408074E0
2015-02-17T18:18:36.133Z,1424197116.133 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1081
2015-02-17T18:18:38.084Z,1424197118.084 [BPC1] Loaded
2015-02-17T18:18:38.084Z,1424197118.084 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-02-17T18:18:38.085Z,1424197118.085 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-02-17T18:18:38.085Z,1424197118.085 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-02-17T18:18:38.190Z,1424197118.190 [BuoyancyServo] Loaded
2015-02-17T18:18:38.191Z,1424197118.191 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-02-17T18:18:38.203Z,1424197118.203 [ElevatorServo] Loaded
2015-02-17T18:18:38.203Z,1424197118.203 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-02-17T18:18:38.216Z,1424197118.216 [MassServo] Loaded
2015-02-17T18:18:38.216Z,1424197118.216 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-02-17T18:18:38.229Z,1424197118.229 [RudderServo] Loaded
2015-02-17T18:18:38.229Z,1424197118.229 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-02-17T18:18:38.241Z,1424197118.241 [ThrusterServo] Loaded
2015-02-17T18:18:38.241Z,1424197118.241 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-02-17T18:18:38.242Z,1424197118.242 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-02-17T18:18:38.242Z,1424197118.242 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-02-17T18:18:38.509Z,1424197118.509 [ExternalSim] Loaded
2015-02-17T18:18:38.510Z,1424197118.510 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2015-02-17T18:18:38.511Z,1424197118.511 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-02-17T18:18:38.511Z,1424197118.511 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-02-17T18:18:38.538Z,1424197118.538 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-02-17T18:18:38.540Z,1424197118.540 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-02-17T18:18:38.541Z,1424197118.541 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-02-17T18:18:38.550Z,1424197118.550 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-02-17T18:18:38.551Z,1424197118.551 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408B84E0
2015-02-17T18:18:38.552Z,1424197118.552 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1082
2015-02-17T18:18:38.556Z,1424197118.556 [Supervisor](INFO): Main Thread ID is 995
2015-02-17T18:18:38.557Z,1424197118.557 [Supervisor](DEBUG): Running supervisor.
2015-02-17T18:18:38.557Z,1424197118.557 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1083
2015-02-17T18:18:38.561Z,1424197118.561 [controlThread ThreadHandler](INFO): Handler Thread ID is 1084
2015-02-17T18:18:38.561Z,1424197118.561 [controlThread](DEBUG): Initializing ControlThread
2015-02-17T18:18:38.562Z,1424197118.562 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-02-17T18:18:38.564Z,1424197118.564 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-02-17T18:18:38.565Z,1424197118.565 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-02-17T18:18:38.565Z,1424197118.565 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-02-17T18:18:38.565Z,1424197118.565 [SBIT](INFO): Initialize SBIT Component.
2015-02-17T18:18:38.566Z,1424197118.566 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12012
2015-02-17T18:18:38.566Z,1424197118.566 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-02-17T18:18:38.566Z,1424197118.566 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-02-17T18:18:38.567Z,1424197118.567 [IBIT](INFO): Initialize IBIT Component.
2015-02-17T18:18:38.568Z,1424197118.568 [CBIT](DEBUG): Initialize CBIT Component.
2015-02-17T18:18:38.568Z,1424197118.568 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-02-17T18:18:38.569Z,1424197118.569 [logger ThreadHandler](INFO): Handler Thread ID is 1085
2015-02-17T18:18:38.594Z,1424197118.594 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-02-17T18:18:38.594Z,1424197118.594 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-02-17T18:18:38.595Z,1424197118.595 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-02-17T18:18:38.595Z,1424197118.595 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-02-17T18:18:38.595Z,1424197118.595 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-02-17T18:18:38.596Z,1424197118.596 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2015-02-17T18:18:38.598Z,1424197118.598 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-02-17T18:18:38.599Z,1424197118.599 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-02-17T18:18:38.599Z,1424197118.599 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2015-02-17T18:18:38.599Z,1424197118.599 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-02-17T18:18:38.600Z,1424197118.600 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-02-17T18:18:38.604Z,1424197118.604 [ExternalSim](INFO): ExternalSim initializing...
2015-02-17T18:18:38.620Z,1424197118.620 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1086
2015-02-17T18:18:38.626Z,1424197118.626 [Radio_Surface](INFO): Powering up
2015-02-17T18:18:38.641Z,1424197118.641 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1087
2015-02-17T18:18:38.652Z,1424197118.652 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-02-17T18:18:38.653Z,1424197118.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-02-17T18:18:38.653Z,1424197118.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-02-17T18:18:38.653Z,1424197118.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-02-17T18:18:38.654Z,1424197118.654 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-02-17T18:18:38.654Z,1424197118.654 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-02-17T18:18:38.654Z,1424197118.654 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-02-17T18:18:38.655Z,1424197118.655 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-02-17T18:18:38.655Z,1424197118.655 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-02-17T18:18:39.356Z,1424197119.356 [ExternalSim](DEBUG): beaconLat = 36.80340
2015-02-17T18:18:39.356Z,1424197119.356 [ExternalSim](DEBUG): beaconLon = -121.82230
2015-02-17T18:18:39.356Z,1424197119.356 [ExternalSim](DEBUG): beaconDepth = 25.00
2015-02-17T18:18:39.612Z,1424197119.612 [ExternalSim](DEBUG): Simulator initialized
2015-02-17T18:18:39.618Z,1424197119.618 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-02-17T18:18:39.628Z,1424197119.628 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-02-17T18:18:39.637Z,1424197119.637 [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:18:39.638Z,1424197119.638 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-02-17T18:18:39.745Z,1424197119.745 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-02-17T18:18:39.757Z,1424197119.757 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-02-17T18:18:39.774Z,1424197119.774 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-02-17T18:18:39.807Z,1424197119.807 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-02-17T18:18:39.829Z,1424197119.829 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-02-17T18:18:39.843Z,1424197119.843 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-02-17T18:18:39.884Z,1424197119.884 [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:18:39.889Z,1424197119.889 [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:18:40.489Z,1424197120.489 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:40.495Z,1424197120.495 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:18:40.651Z,1424197120.651 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:18:40.657Z,1424197120.657 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-02-17T18:18:40.672Z,1424197120.672 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:18:40.677Z,1424197120.677 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-02-17T18:18:40.699Z,1424197120.699 [MassServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:18:40.705Z,1424197120.705 [MassServo](DEBUG): Initializing MassServo.
2015-02-17T18:18:40.711Z,1424197120.711 [RudderServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:18:40.717Z,1424197120.717 [RudderServo](DEBUG): Initializing RudderServo.
2015-02-17T18:18:40.723Z,1424197120.723 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-02-17T18:18:40.729Z,1424197120.729 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-02-17T18:18:41.074Z,1424197121.074 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:41.075Z,1424197121.075 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:18:50.113Z,1424197130.113 [NAL9602](INFO): Powering up NAL9602
2015-02-17T18:18:50.160Z,1424197130.160 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:50.161Z,1424197130.161 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:18:50.687Z,1424197130.687 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:50.688Z,1424197130.688 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:18:51.159Z,1424197131.159 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:51.160Z,1424197131.160 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:18:51.472Z,1424197131.472 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003506
2015-02-17T18:18:51.580Z,1424197131.580 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:51.580Z,1424197131.580 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T18:18:51.901Z,1424197131.901 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:52.373Z,1424197132.373 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:52.690Z,1424197132.690 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:53.111Z,1424197133.111 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:53.949Z,1424197133.949 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:54.493Z,1424197134.493 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:54.685Z,1424197134.685 [SBIT](IMPORTANT): Beginning Startup BIT
2015-02-17T18:18:54.687Z,1424197134.687 [CBIT](IMPORTANT): Beginning GF scan
2015-02-17T18:18:55.158Z,1424197135.158 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:55.607Z,1424197135.607 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:56.015Z,1424197136.015 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:56.433Z,1424197136.433 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:56.836Z,1424197136.836 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:57.210Z,1424197137.210 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:57.641Z,1424197137.641 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:58.054Z,1424197138.054 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:58.455Z,1424197138.455 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:58.947Z,1424197138.947 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:18:59.619Z,1424197139.619 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:00.046Z,1424197140.046 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:00.414Z,1424197140.414 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:00.874Z,1424197140.874 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:01.202Z,1424197141.202 [NAL9602](INFO): NAL9602 initialized
2015-02-17T18:19:01.228Z,1424197141.228 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:
2015-02-17T18:19:01.237Z,1424197141.237 [BPC1](ERROR): Failed to parse bank A battery data
2015-02-17T18:19:01.238Z,1424197141.238 [BPC1] Data Fault, FailCount= 1
2015-02-17T18:19:01.238Z,1424197141.238 [BPC1](ERROR): Data Fault
2015-02-17T18:19:01.251Z,1424197141.251 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:01.377Z,1424197141.377 [CBIT](ERROR): Data Fault in component: BPC1
2015-02-17T18:19:01.679Z,1424197141.679 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:02.044Z,1424197142.044 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:02.445Z,1424197142.445 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:02.582Z,1424197142.582 [CBIT](INFO): Clearing failed state for component BPC1
2015-02-17T18:19:02.582Z,1424197142.582 [BPC1] No Fault, FailCount= 1
2015-02-17T18:19:02.979Z,1424197142.979 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:03.383Z,1424197143.383 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:03.777Z,1424197143.777 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:04.163Z,1424197144.163 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:04.694Z,1424197144.694 [NAL9602](INFO): Flushing. SigQuality: -1
2015-02-17T18:19:04.695Z,1424197144.695 [NAL9602](INFO): Response:
$GPGSV,4,2,14,11,,,45,14,,,44,18,,,38,19,,,42*72

OK
2015-02-17T18:19:04.741Z,1424197144.741 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:05.162Z,1424197145.162 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:05.518Z,1424197145.518 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:05.935Z,1424197145.935 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:06.311Z,1424197146.311 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:06.763Z,1424197146.763 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:07.153Z,1424197147.153 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:07.616Z,1424197147.616 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:08.040Z,1424197148.040 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:08.407Z,1424197148.407 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:08.798Z,1424197148.798 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:09.175Z,1424197149.175 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:09.672Z,1424197149.672 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:10.417Z,1424197150.417 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:10.823Z,1424197150.823 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:11.203Z,1424197151.203 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:11.593Z,1424197151.593 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:19:11.593Z,1424197151.593 [NAL9602](INFO): Response:
+CSQ:0

OK4,11,,,45,14,,,44,18,,,38,19,,,42*72

OK
2015-02-17T18:19:11.655Z,1424197151.655 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:12.004Z,1424197152.004 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:12.417Z,1424197152.417 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:12.826Z,1424197152.826 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:13.214Z,1424197153.214 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:13.583Z,1424197153.583 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:14.020Z,1424197154.020 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:14.473Z,1424197154.473 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:14.933Z,1424197154.933 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:15.426Z,1424197155.426 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:15.792Z,1424197155.792 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:19:15.792Z,1424197155.792 [NAL9602](INFO): Response:
+CSQ:0

OK4,11,,,45,14,,,44,18,,,38,19,,,42*72

OK
2015-02-17T18:19:15.807Z,1424197155.807 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:16.239Z,1424197156.239 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:16.603Z,1424197156.603 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:17.038Z,1424197157.038 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:17.425Z,1424197157.425 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:17.799Z,1424197157.799 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:18.202Z,1424197158.202 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:18.709Z,1424197158.709 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:19.055Z,1424197159.055 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:19.458Z,1424197159.458 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:20.161Z,1424197160.161 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:20.510Z,1424197160.510 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:20.926Z,1424197160.926 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:21.061Z,1424197161.061 [CBIT](IMPORTANT): No ground fault detected
2015-02-17T18:19:21.427Z,1424197161.427 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:21.758Z,1424197161.758 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:22.164Z,1424197162.164 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:22.606Z,1424197162.606 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:23.013Z,1424197163.013 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:23.251Z,1424197163.251 [CommandLine](IMPORTANT): got command quit
2015-02-17T18:19:23.518Z,1424197163.518 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:23.898Z,1424197163.898 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:24.256Z,1424197164.256 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:19:24.256Z,1424197164.256 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:24.280Z,1424197164.280 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:24.373Z,1424197164.373 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-02-17T18:19:24.373Z,1424197164.373 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:24.374Z,1424197164.374 [CommandLine](INFO): Join timeout helper Thread ID is 1101
2015-02-17T18:19:24.381Z,1424197164.381 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-02-17T18:19:24.381Z,1424197164.381 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:24.382Z,1424197164.382 [NavChartDb](INFO): Join timeout helper Thread ID is 1102
2015-02-17T18:19:24.669Z,1424197164.669 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T18:19:24.670Z,1424197164.670 [NAL9602](INFO): Response:
+CSQ:0

OK4,11,,,45,14,,,44,18,,,38,19,,,42*72

OK
2015-02-17T18:19:24.768Z,1424197164.768 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:25.221Z,1424197165.221 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:25.326Z,1424197165.326 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:19:25.326Z,1424197165.326 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.334Z,1424197165.334 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-02-17T18:19:25.335Z,1424197165.335 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.335Z,1424197165.335 [Radio_Surface](INFO): Join timeout helper Thread ID is 1103
2015-02-17T18:19:25.515Z,1424197165.515 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:19:25.516Z,1424197165.516 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.523Z,1424197165.523 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-02-17T18:19:25.523Z,1424197165.523 [logger ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.523Z,1424197165.523 [logger](INFO): Join timeout helper Thread ID is 1104
2015-02-17T18:19:25.531Z,1424197165.531 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:19:25.531Z,1424197165.531 [logger ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.567Z,1424197165.567 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-02-17T18:19:25.567Z,1424197165.567 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.567Z,1424197165.567 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-02-17T18:19:25.567Z,1424197165.567 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.568Z,1424197165.568 [controlThread](INFO): Join timeout helper Thread ID is 1105
2015-02-17T18:19:25.587Z,1424197165.587 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T18:19:25.669Z,1424197165.669 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T18:19:25.669Z,1424197165.669 [controlThread](DEBUG): Uninitializing ControlThread
2015-02-17T18:19:25.670Z,1424197165.670 [NAL9602](INFO): Powering down
2015-02-17T18:19:25.672Z,1424197165.672 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-02-17T18:19:25.674Z,1424197165.674 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-02-17T18:19:25.678Z,1424197165.678 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-02-17T18:19:25.678Z,1424197165.678 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-02-17T18:19:25.679Z,1424197165.679 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-02-17T18:19:25.679Z,1424197165.679 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-02-17T18:19:25.680Z,1424197165.680 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-02-17T18:19:25.680Z,1424197165.680 [BuoyancyServo](INFO): Powering down
2015-02-17T18:19:25.691Z,1424197165.691 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-02-17T18:19:25.691Z,1424197165.691 [ElevatorServo](INFO): Powering down
2015-02-17T18:19:25.692Z,1424197165.692 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-02-17T18:19:25.692Z,1424197165.692 [MassServo](INFO): Powering down
2015-02-17T18:19:25.693Z,1424197165.693 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-02-17T18:19:25.693Z,1424197165.693 [RudderServo](INFO): Powering down
2015-02-17T18:19:25.694Z,1424197165.694 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-02-17T18:19:25.694Z,1424197165.694 [ThrusterServo](INFO): Powering down
2015-02-17T18:19:25.695Z,1424197165.695 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-02-17T18:19:25.696Z,1424197165.696 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-02-17T18:19:25.696Z,1424197165.696 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-02-17T18:19:25.728Z,1424197165.728 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:25.852Z,1424197165.852 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:26.019Z,1424197166.019 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T18:19:26.069Z,1424197166.069 [logger ThreadHandler](INFO): Thread cancelled.