2013-09-15T00:59:36.582Z,1379206776.582 [Supervisor](DEBUG): Initializing supervisor.
2013-09-15T00:59:36.584Z,1379206776.584 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-09-15T00:59:36.585Z,1379206776.585 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-09-15T00:59:36.586Z,1379206776.586 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-09-15T00:59:36.590Z,1379206776.590 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-09-15T00:59:36.600Z,1379206776.600 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-09-15T00:59:36.601Z,1379206776.601 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-09-15T00:59:36.602Z,1379206776.602 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-09-15T00:59:36.603Z,1379206776.603 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-09-15T00:59:36.604Z,1379206776.604 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-09-15T00:59:36.605Z,1379206776.605 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-09-15T00:59:36.931Z,1379206776.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-09-15T00:59:36.931Z,1379206776.931 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-09-15T00:59:37.125Z,1379206777.125 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-09-15T00:59:37.125Z,1379206777.125 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-09-15T00:59:37.211Z,1379206777.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-09-15T00:59:37.212Z,1379206777.212 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-09-15T00:59:37.324Z,1379206777.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-09-15T00:59:37.325Z,1379206777.325 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-09-15T00:59:37.463Z,1379206777.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-09-15T00:59:37.464Z,1379206777.464 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-09-15T00:59:37.702Z,1379206777.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-09-15T00:59:37.703Z,1379206777.703 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-09-15T00:59:37.870Z,1379206777.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-09-15T00:59:37.871Z,1379206777.871 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-09-15T00:59:38.132Z,1379206778.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-09-15T00:59:38.133Z,1379206778.133 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-09-15T00:59:38.236Z,1379206778.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-09-15T00:59:38.236Z,1379206778.236 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-09-15T00:59:38.646Z,1379206778.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-09-15T00:59:38.647Z,1379206778.647 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-09-15T00:59:38.758Z,1379206778.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-09-15T00:59:38.759Z,1379206778.759 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-09-15T00:59:38.847Z,1379206778.847 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-09-15T00:59:38.848Z,1379206778.848 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-09-15T00:59:38.947Z,1379206778.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-09-15T00:59:39.074Z,1379206779.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-09-15T00:59:39.169Z,1379206779.169 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-09-15T00:59:39.275Z,1379206779.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-09-15T00:59:39.371Z,1379206779.371 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-09-15T00:59:39.487Z,1379206779.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-09-15T00:59:39.584Z,1379206779.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-09-15T00:59:39.670Z,1379206779.670 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-09-15T00:59:39.672Z,1379206779.672 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-09-15T00:59:39.838Z,1379206779.838 [InternalSim] Loaded
2013-09-15T00:59:39.839Z,1379206779.839 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-09-15T00:59:39.839Z,1379206779.839 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-09-15T00:59:39.840Z,1379206779.840 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-09-15T00:59:39.928Z,1379206779.928 [SBIT](DEBUG): Construct Startup Built In Test.
2013-09-15T00:59:39.957Z,1379206779.957 [SBIT] Loaded
2013-09-15T00:59:39.957Z,1379206779.957 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-09-15T00:59:39.958Z,1379206779.958 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-09-15T00:59:39.987Z,1379206779.987 [IBIT] Loaded
2013-09-15T00:59:39.987Z,1379206779.987 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-09-15T00:59:39.990Z,1379206779.990 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-09-15T00:59:40.105Z,1379206780.105 [CBIT] Loaded
2013-09-15T00:59:40.105Z,1379206780.105 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-09-15T00:59:40.106Z,1379206780.106 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-09-15T00:59:40.107Z,1379206780.107 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-09-15T00:59:40.276Z,1379206780.276 [BuoyancyServo] Loaded
2013-09-15T00:59:40.276Z,1379206780.276 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-09-15T00:59:40.288Z,1379206780.288 [ElevatorServo] Loaded
2013-09-15T00:59:40.288Z,1379206780.288 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-09-15T00:59:40.299Z,1379206780.299 [MassServo] Loaded
2013-09-15T00:59:40.299Z,1379206780.299 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-09-15T00:59:40.311Z,1379206780.311 [RudderServo] Loaded
2013-09-15T00:59:40.311Z,1379206780.311 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-09-15T00:59:40.322Z,1379206780.322 [ThrusterServo] Loaded
2013-09-15T00:59:40.323Z,1379206780.323 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-09-15T00:59:40.323Z,1379206780.323 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-09-15T00:59:40.324Z,1379206780.324 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-09-15T00:59:40.359Z,1379206780.359 [DepthRateCalculator] Loaded
2013-09-15T00:59:40.359Z,1379206780.359 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-09-15T00:59:43.504Z,1379206783.504 [HFRadarModelCalc] Loaded
2013-09-15T00:59:43.505Z,1379206783.505 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-09-15T00:59:43.521Z,1379206783.521 [NavChart] Loaded
2013-09-15T00:59:43.521Z,1379206783.521 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-09-15T00:59:43.527Z,1379206783.527 [PitchRateCalculator] Loaded
2013-09-15T00:59:43.527Z,1379206783.527 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-09-15T00:59:43.538Z,1379206783.538 [SpeedCalculator] Loaded
2013-09-15T00:59:43.538Z,1379206783.538 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-09-15T00:59:43.554Z,1379206783.554 [TempGradientCalculator] Loaded
2013-09-15T00:59:43.555Z,1379206783.555 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-09-15T00:59:43.561Z,1379206783.561 [YawRateCalculator] Loaded
2013-09-15T00:59:43.561Z,1379206783.561 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-09-15T00:59:43.608Z,1379206783.608 [Navigation] Loaded
2013-09-15T00:59:43.608Z,1379206783.608 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-09-15T00:59:43.609Z,1379206783.609 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-09-15T00:59:43.609Z,1379206783.609 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-09-15T00:59:43.887Z,1379206783.887 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-09-15T00:59:43.889Z,1379206783.889 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-09-15T00:59:43.931Z,1379206783.931 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-09-15T00:59:43.932Z,1379206783.932 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-09-15T00:59:43.985Z,1379206783.985 [VerticalControl](DEBUG): Construct VerticalControl.
2013-09-15T00:59:44.079Z,1379206784.079 [VerticalControl] Loaded
2013-09-15T00:59:44.079Z,1379206784.079 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-09-15T00:59:44.080Z,1379206784.080 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-09-15T00:59:44.138Z,1379206784.138 [HorizontalControl] Loaded
2013-09-15T00:59:44.138Z,1379206784.138 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-09-15T00:59:44.139Z,1379206784.139 [SpeedControl](DEBUG): Construct SpeedControl.
2013-09-15T00:59:44.141Z,1379206784.141 [SpeedControl] Loaded
2013-09-15T00:59:44.141Z,1379206784.141 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-09-15T00:59:44.142Z,1379206784.142 [LoopControl](DEBUG): Construct LoopControl.
2013-09-15T00:59:44.142Z,1379206784.142 [LoopControl] Loaded
2013-09-15T00:59:44.142Z,1379206784.142 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-09-15T00:59:44.143Z,1379206784.143 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-09-15T00:59:44.143Z,1379206784.143 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-09-15T00:59:44.149Z,1379206784.149 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-09-15T00:59:44.154Z,1379206784.154 [AsyncPiEstimator] Loaded
2013-09-15T00:59:44.155Z,1379206784.155 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-09-15T00:59:44.156Z,1379206784.156 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0
2013-09-15T00:59:44.157Z,1379206784.157 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-09-15T00:59:44.157Z,1379206784.157 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-09-15T00:59:44.355Z,1379206784.355 [AHRS_sp3003D] Loaded
2013-09-15T00:59:44.355Z,1379206784.355 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-09-15T00:59:44.369Z,1379206784.369 [Depth_Keller] Loaded
2013-09-15T00:59:44.369Z,1379206784.369 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-09-15T00:59:44.374Z,1379206784.374 [DropWeight] Loaded
2013-09-15T00:59:44.375Z,1379206784.375 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-09-15T00:59:44.558Z,1379206784.558 [DVL_micro] Loaded
2013-09-15T00:59:44.558Z,1379206784.558 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-09-15T00:59:44.560Z,1379206784.560 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406D54E0
2013-09-15T00:59:44.648Z,1379206784.648 [NAL9602] Loaded
2013-09-15T00:59:44.649Z,1379206784.649 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-09-15T00:59:44.692Z,1379206784.692 [Onboard] Loaded
2013-09-15T00:59:44.692Z,1379206784.692 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-09-15T00:59:44.699Z,1379206784.699 [Radio_Freewave] Loaded
2013-09-15T00:59:44.700Z,1379206784.700 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-09-15T00:59:44.841Z,1379206784.841 [DAT] Loaded
2013-09-15T00:59:44.841Z,1379206784.841 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-09-15T00:59:44.842Z,1379206784.842 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-09-15T00:59:44.842Z,1379206784.842 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-09-15T00:59:44.908Z,1379206784.908 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-09-15T00:59:44.911Z,1379206784.911 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-09-15T00:59:44.911Z,1379206784.911 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-09-15T00:59:44.918Z,1379206784.918 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-09-15T00:59:44.919Z,1379206784.919 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407324E0
2013-09-15T00:59:44.923Z,1379206784.923 [Supervisor](DEBUG): Running supervisor.
2013-09-15T00:59:44.924Z,1379206784.924 [CommandLine](INFO): Thread ID is 863
2013-09-15T00:59:44.927Z,1379206784.927 [controlThread](INFO): Thread ID is 862
2013-09-15T00:59:44.927Z,1379206784.927 [controlThread](DEBUG): Initializing ControlThread
2013-09-15T00:59:44.928Z,1379206784.928 [CycleStarter](INFO): Thread ID is 861
2013-09-15T00:59:44.928Z,1379206784.928 [InternalSim](DEBUG):  InternalSim initializing...
2013-09-15T00:59:44.963Z,1379206784.963 [logger](INFO): Thread ID is 864
2013-09-15T00:59:44.978Z,1379206784.978 [SBIT](INFO): Initialize SBIT Component.
2013-09-15T00:59:44.979Z,1379206784.979 [SBIT](IMPORTANT): Tethys CM Info: 
$Rev:10573
2013-09-15T00:59:44.979Z,1379206784.979 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-09-15T00:59:44.979Z,1379206784.979 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-09-15T00:59:44.980Z,1379206784.980 [IBIT](INFO): Initialize IBIT Component.
2013-09-15T00:59:44.981Z,1379206784.981 [CBIT](DEBUG): Initialize CBIT Component.
2013-09-15T00:59:44.981Z,1379206784.981 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-09-15T00:59:44.994Z,1379206784.994 [AsyncPiEstimator](INFO): Thread ID is 925
2013-09-15T00:59:44.994Z,1379206784.994 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-09-15T00:59:45.007Z,1379206785.007 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-09-15T00:59:45.007Z,1379206785.007 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-09-15T00:59:45.008Z,1379206785.008 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-09-15T00:59:45.008Z,1379206785.008 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-09-15T00:59:45.008Z,1379206785.008 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-09-15T00:59:45.009Z,1379206785.009 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-09-15T00:59:45.009Z,1379206785.009 [Navigation](DEBUG): Initializing Navigation.
2013-09-15T00:59:45.010Z,1379206785.010 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-09-15T00:59:45.011Z,1379206785.011 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-09-15T00:59:45.012Z,1379206785.012 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-09-15T00:59:45.013Z,1379206785.013 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-09-15T00:59:45.023Z,1379206785.023 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-09-15T00:59:45.030Z,1379206785.030 [DVL_micro](INFO): Thread ID is 926
2013-09-15T00:59:45.039Z,1379206785.039 [DVL_micro](INFO): Initializing
2013-09-15T00:59:45.039Z,1379206785.039 [DVL_micro](INFO): start:Powering up
2013-09-15T00:59:45.040Z,1379206785.040 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T00:59:45.041Z,1379206785.041 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T00:59:45.054Z,1379206785.054 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-15T00:59:45.058Z,1379206785.058 [NavChartDb](INFO): Thread ID is 927
2013-09-15T00:59:45.061Z,1379206785.061 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-09-15T00:59:45.062Z,1379206785.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-09-15T00:59:45.062Z,1379206785.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-09-15T00:59:45.062Z,1379206785.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-09-15T00:59:45.062Z,1379206785.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-09-15T00:59:45.063Z,1379206785.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-09-15T00:59:45.063Z,1379206785.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-09-15T00:59:45.063Z,1379206785.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-09-15T00:59:45.063Z,1379206785.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-09-15T00:59:45.119Z,1379206785.119 [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 RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-09-15T00:59:45.120Z,1379206785.120 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-09-15T00:59:45.202Z,1379206785.202 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-09-15T00:59:45.204Z,1379206785.204 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-09-15T00:59:45.207Z,1379206785.207 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-15T00:59:45.240Z,1379206785.240 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-09-15T00:59:45.243Z,1379206785.243 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-15T00:59:45.262Z,1379206785.262 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-09-15T00:59:45.295Z,1379206785.295 [Default:D.SetSpeed](DEBUG): Construct.
2013-09-15T00:59:45.310Z,1379206785.310 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-15T00:59:45.315Z,1379206785.315 [Default:F.Wait](DEBUG): Construct Wait.
2013-09-15T00:59:45.327Z,1379206785.327 [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="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS" >

        <When>
            <Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS">
            <Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute RunIn="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="CallIridium" >

        <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>

        <Assign><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

<!-- Wait forever at the surface-->

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

    <Guidance:Wait RunIn="Sequence"></Guidance:Wait>

</Mission>


2013-09-15T00:59:45.334Z,1379206785.334 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-09-15T00:59:45.393Z,1379206785.393 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T00:59:45.601Z,1379206785.601 [Radio_Freewave](INFO): Powering up
2013-09-15T00:59:45.618Z,1379206785.618 [DAT](INFO): Powering up
2013-09-15T00:59:45.618Z,1379206785.618 [DAT](DEBUG): Initializing DAT.
2013-09-15T00:59:45.825Z,1379206785.825 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-09-15T00:59:45.831Z,1379206785.831 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-09-15T00:59:45.837Z,1379206785.837 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-09-15T00:59:45.843Z,1379206785.843 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-09-15T00:59:45.849Z,1379206785.849 [MassServo](DEBUG): Initializing EZServoServo.
2013-09-15T00:59:45.855Z,1379206785.855 [MassServo](DEBUG): Initializing MassServo.
2013-09-15T00:59:45.861Z,1379206785.861 [RudderServo](DEBUG): Initializing EZServoServo.
2013-09-15T00:59:45.891Z,1379206785.891 [RudderServo](DEBUG): Initializing RudderServo.
2013-09-15T00:59:45.912Z,1379206785.912 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-09-15T00:59:45.919Z,1379206785.919 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-09-15T00:59:45.960Z,1379206785.960 [CBIT](FAULT): Main Battery Failure. Count: 1
2013-09-15T00:59:46.396Z,1379206786.396 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T00:59:46.396Z,1379206786.396 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T00:59:46.396Z,1379206786.396 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-09-15T00:59:46.396Z,1379206786.396 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T00:59:46.883Z,1379206786.883 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T00:59:46.918Z,1379206786.918 [AHRS_sp3003D](INFO): Powering down
2013-09-15T00:59:47.137Z,1379206787.137 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T00:59:47.137Z,1379206787.137 [DVL_micro](INFO): Querying output modes
2013-09-15T00:59:47.138Z,1379206787.138 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T00:59:48.305Z,1379206788.305 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T00:59:48.305Z,1379206788.305 [AHRS_sp3003D] No Fault, FailCount= 1
2013-09-15T00:59:48.499Z,1379206788.499 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T00:59:49.144Z,1379206789.144 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T00:59:49.144Z,1379206789.144 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T00:59:49.144Z,1379206789.144 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T00:59:49.633Z,1379206789.633 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T00:59:49.633Z,1379206789.633 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T00:59:49.633Z,1379206789.633 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2013-09-15T00:59:49.633Z,1379206789.633 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T00:59:50.192Z,1379206790.192 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T00:59:50.221Z,1379206790.221 [AHRS_sp3003D](INFO): Powering down
2013-09-15T00:59:50.312Z,1379206790.312 [NAL9602](INFO): Powering up NAL9602
2013-09-15T00:59:51.147Z,1379206791.147 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T00:59:51.152Z,1379206791.152 [DVL_micro](INFO): pause:Powering down
2013-09-15T00:59:51.154Z,1379206791.154 [DVL_micro](INFO): NQ1 requested
2013-09-15T00:59:51.155Z,1379206791.155 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T00:59:51.155Z,1379206791.155 [DVL_micro](INFO): resume:Powering up
2013-09-15T00:59:51.155Z,1379206791.155 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T00:59:51.479Z,1379206791.479 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T00:59:51.480Z,1379206791.480 [AHRS_sp3003D] No Fault, FailCount= 2
2013-09-15T00:59:51.808Z,1379206791.808 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T00:59:52.950Z,1379206792.950 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T00:59:52.950Z,1379206792.950 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T00:59:52.950Z,1379206792.950 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2013-09-15T00:59:52.950Z,1379206792.950 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T00:59:53.023Z,1379206793.023 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T00:59:53.049Z,1379206793.049 [AHRS_sp3003D](INFO): Powering down
2013-09-15T00:59:53.159Z,1379206793.159 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T00:59:53.159Z,1379206793.159 [DVL_micro](INFO): Querying output modes
2013-09-15T00:59:53.159Z,1379206793.159 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T00:59:54.298Z,1379206794.298 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T00:59:54.298Z,1379206794.298 [AHRS_sp3003D] No Fault, FailCount= 3
2013-09-15T00:59:54.641Z,1379206794.641 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T00:59:55.173Z,1379206795.173 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T00:59:55.173Z,1379206795.173 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T00:59:55.174Z,1379206795.174 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T00:59:55.774Z,1379206795.774 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T00:59:55.774Z,1379206795.774 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T00:59:55.774Z,1379206795.774 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2013-09-15T00:59:55.774Z,1379206795.774 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T00:59:55.840Z,1379206795.840 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T00:59:55.865Z,1379206795.865 [AHRS_sp3003D](INFO): Powering down
2013-09-15T00:59:57.119Z,1379206797.119 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T00:59:57.119Z,1379206797.119 [AHRS_sp3003D] No Fault, FailCount= 4
2013-09-15T00:59:57.184Z,1379206797.184 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T00:59:57.187Z,1379206797.187 [DVL_micro](INFO): pause:Powering down
2013-09-15T00:59:57.457Z,1379206797.457 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T00:59:58.586Z,1379206798.586 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T00:59:58.587Z,1379206798.587 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T00:59:58.587Z,1379206798.587 [AHRS_sp3003D] Hardware Fault, FailCount= 5
2013-09-15T00:59:58.587Z,1379206798.587 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T00:59:58.625Z,1379206798.625 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T00:59:58.626Z,1379206798.626 [CBIT](CRITICAL): Hardware Fault in component: AHRS_sp3003D
2013-09-15T00:59:58.665Z,1379206798.665 [AHRS_sp3003D](INFO): Powering down
2013-09-15T00:59:58.795Z,1379206798.795 [DVL_micro](INFO): NQ1 requested
2013-09-15T00:59:58.796Z,1379206798.796 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T00:59:58.796Z,1379206798.796 [DVL_micro](INFO): resume:Powering up
2013-09-15T00:59:58.796Z,1379206798.796 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T00:59:58.820Z,1379206798.820 [CommandLine](FAULT): Scheduling is paused
2013-09-15T01:00:00.704Z,1379206800.704 [SBIT](IMPORTANT): Beginning Startup BIT
2013-09-15T01:00:00.711Z,1379206800.711 [CBIT](IMPORTANT): Beginning GF scan
2013-09-15T01:00:00.802Z,1379206800.802 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:00:00.803Z,1379206800.803 [DVL_micro](INFO): Querying output modes
2013-09-15T01:00:00.803Z,1379206800.803 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:00:01.099Z,1379206801.099 [NAL9602](INFO): NAL9602 initialized
2013-09-15T01:00:02.805Z,1379206802.805 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:02.805Z,1379206802.805 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:00:02.805Z,1379206802.805 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:00:04.812Z,1379206804.812 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:04.814Z,1379206804.814 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:00:04.814Z,1379206804.814 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:00:05.489Z,1379206805.489 [DAT](INFO): Powering down
2013-09-15T01:00:06.820Z,1379206806.820 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:00:06.820Z,1379206806.820 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:00:08.822Z,1379206808.822 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:08.822Z,1379206808.822 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:00:08.823Z,1379206808.823 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:00:10.834Z,1379206810.834 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:10.834Z,1379206810.834 [DVL_micro](INFO): Querying output modes
2013-09-15T01:00:10.834Z,1379206810.834 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:00:12.845Z,1379206812.845 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:12.845Z,1379206812.845 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:00:12.845Z,1379206812.845 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:00:14.852Z,1379206814.852 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:16.856Z,1379206816.856 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:00:16.856Z,1379206816.856 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:00:18.858Z,1379206818.858 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:00:18.859Z,1379206818.859 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:00:20.871Z,1379206820.871 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:20.871Z,1379206820.871 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:00:20.871Z,1379206820.871 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:00:22.880Z,1379206822.880 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:22.880Z,1379206822.880 [DVL_micro](INFO): Querying output modes
2013-09-15T01:00:22.880Z,1379206822.880 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:00:24.887Z,1379206824.887 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:24.887Z,1379206824.887 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:00:24.888Z,1379206824.888 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:00:26.898Z,1379206826.898 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:27.096Z,1379206827.096 [CBIT](IMPORTANT): No ground fault detected
2013-09-15T01:00:28.902Z,1379206828.902 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:00:28.902Z,1379206828.902 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:00:30.905Z,1379206830.905 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:00:30.905Z,1379206830.905 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:00:32.912Z,1379206832.912 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:32.912Z,1379206832.912 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:00:32.912Z,1379206832.912 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:00:34.923Z,1379206834.923 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:34.923Z,1379206834.923 [DVL_micro](INFO): Querying output modes
2013-09-15T01:00:34.923Z,1379206834.923 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:00:36.926Z,1379206836.926 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:36.926Z,1379206836.926 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:00:36.926Z,1379206836.926 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:00:38.937Z,1379206838.937 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:40.949Z,1379206840.949 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:00:40.949Z,1379206840.949 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:00:42.952Z,1379206842.952 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:00:42.952Z,1379206842.952 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:00:44.958Z,1379206844.958 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:44.958Z,1379206844.958 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:00:44.959Z,1379206844.959 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:00:46.982Z,1379206846.982 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:46.982Z,1379206846.982 [DVL_micro](INFO): Querying output modes
2013-09-15T01:00:46.982Z,1379206846.982 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:00:48.985Z,1379206848.985 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:48.985Z,1379206848.985 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:00:48.985Z,1379206848.985 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:00:50.998Z,1379206850.998 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:53.011Z,1379206853.011 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:00:53.012Z,1379206853.012 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:00:54.527Z,1379206854.527 [SBIT](IMPORTANT): SBIT PASSED
2013-09-15T01:00:54.916Z,1379206854.916 [MissionManager](IMPORTANT): Started mission Startup
2013-09-15T01:00:54.916Z,1379206854.916 [Startup] Running Loop=1
2013-09-15T01:00:54.917Z,1379206854.917 [Startup](INFO): Aggregate::initialize Startup
2013-09-15T01:00:54.917Z,1379206854.917 [Startup:A.GoToSurface] Running Loop=1
2013-09-15T01:00:54.917Z,1379206854.917 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-15T01:00:54.922Z,1379206854.922 [Startup:StartupSatComms] Running Loop=1
2013-09-15T01:00:54.923Z,1379206854.923 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-09-15T01:00:54.923Z,1379206854.923 [Startup:StartupSatComms:A] Running Loop=1
2013-09-15T01:00:55.014Z,1379206855.014 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:00:55.015Z,1379206855.015 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:00:55.328Z,1379206855.328 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-09-15T01:00:57.021Z,1379206857.021 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:57.021Z,1379206857.021 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:00:57.021Z,1379206857.021 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:00:59.024Z,1379206859.024 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:00:59.024Z,1379206859.024 [DVL_micro](INFO): Querying output modes
2013-09-15T01:00:59.024Z,1379206859.024 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:01:01.035Z,1379206861.035 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:01.035Z,1379206861.035 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:01:01.036Z,1379206861.036 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:01:03.046Z,1379206863.046 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:05.050Z,1379206865.050 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:01:05.050Z,1379206865.050 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:01:07.053Z,1379206867.053 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:01:07.053Z,1379206867.053 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:01:09.060Z,1379206869.060 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:09.060Z,1379206869.060 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:01:09.060Z,1379206869.060 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:01:11.071Z,1379206871.071 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:11.071Z,1379206871.071 [DVL_micro](INFO): Querying output modes
2013-09-15T01:01:11.071Z,1379206871.071 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:01:13.082Z,1379206873.082 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:13.082Z,1379206873.082 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:01:13.082Z,1379206873.082 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:01:15.085Z,1379206875.085 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:17.089Z,1379206877.089 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:01:17.089Z,1379206877.089 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:01:19.092Z,1379206879.092 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:01:19.092Z,1379206879.092 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:01:21.094Z,1379206881.094 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:21.094Z,1379206881.094 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:01:21.095Z,1379206881.095 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:01:23.105Z,1379206883.105 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:23.106Z,1379206883.106 [DVL_micro](INFO): Querying output modes
2013-09-15T01:01:23.106Z,1379206883.106 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:01:25.109Z,1379206885.109 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:25.109Z,1379206885.109 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:01:25.109Z,1379206885.109 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:01:27.120Z,1379206887.120 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:29.132Z,1379206889.132 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:01:29.132Z,1379206889.132 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:01:31.134Z,1379206891.134 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:01:31.135Z,1379206891.135 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:01:33.141Z,1379206893.141 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:33.141Z,1379206893.141 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:01:33.141Z,1379206893.141 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:01:35.144Z,1379206895.144 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:35.144Z,1379206895.144 [DVL_micro](INFO): Querying output modes
2013-09-15T01:01:35.144Z,1379206895.144 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:01:37.147Z,1379206897.147 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:37.147Z,1379206897.147 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:01:37.148Z,1379206897.148 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:01:39.150Z,1379206899.150 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:41.162Z,1379206901.162 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:01:41.162Z,1379206901.162 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:01:43.165Z,1379206903.165 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:01:43.165Z,1379206903.165 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:01:45.168Z,1379206905.168 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:45.168Z,1379206905.168 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:01:45.168Z,1379206905.168 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:01:47.179Z,1379206907.179 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:47.179Z,1379206907.179 [DVL_micro](INFO): Querying output modes
2013-09-15T01:01:47.179Z,1379206907.179 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:01:49.190Z,1379206909.190 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:49.190Z,1379206909.190 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:01:49.190Z,1379206909.190 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:01:51.201Z,1379206911.201 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:53.205Z,1379206913.205 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:01:53.205Z,1379206913.205 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:01:55.208Z,1379206915.208 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:01:55.208Z,1379206915.208 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:01:55.330Z,1379206915.330 [Startup:StartupSatComms:A](INFO): Timed out from 2013-09-15T01:00:54.9Z
2013-09-15T01:01:55.330Z,1379206915.330 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-09-15T01:01:55.330Z,1379206915.330 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-09-15T01:01:55.330Z,1379206915.330 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-09-15T01:01:55.331Z,1379206915.331 [Startup:StartupSatComms:A] Stopped
2013-09-15T01:01:55.331Z,1379206915.331 [Startup:StartupSatComms:B] Running Loop=1
2013-09-15T01:01:55.739Z,1379206915.739 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-09-15T01:01:56.923Z,1379206916.923 [CBIT](CRITICAL): Environmental Failure. Press:14.982194 PSI. Humidity:44%. Temp:22 C. ABORTING MISSION
2013-09-15T01:01:57.218Z,1379206917.218 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:57.218Z,1379206917.218 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:01:57.219Z,1379206917.219 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:01:59.221Z,1379206919.221 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:01:59.222Z,1379206919.222 [DVL_micro](INFO): Querying output modes
2013-09-15T01:01:59.222Z,1379206919.222 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:02:01.233Z,1379206921.233 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:01.233Z,1379206921.233 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:02:01.233Z,1379206921.233 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:02:03.236Z,1379206923.236 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:05.247Z,1379206925.247 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:02:05.248Z,1379206925.248 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:02:07.250Z,1379206927.250 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:02:07.251Z,1379206927.251 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:02:09.253Z,1379206929.253 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:09.253Z,1379206929.253 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:02:09.253Z,1379206929.253 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:02:11.265Z,1379206931.265 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:11.265Z,1379206931.265 [DVL_micro](INFO): Querying output modes
2013-09-15T01:02:11.265Z,1379206931.265 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:02:13.271Z,1379206933.271 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:13.271Z,1379206933.271 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:02:13.272Z,1379206933.272 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:02:15.283Z,1379206935.283 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:17.286Z,1379206937.286 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:02:17.286Z,1379206937.286 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:02:19.289Z,1379206939.289 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:02:19.289Z,1379206939.289 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:02:21.300Z,1379206941.300 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:21.300Z,1379206941.300 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:02:21.300Z,1379206941.300 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:02:23.307Z,1379206943.307 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:23.307Z,1379206943.307 [DVL_micro](INFO): Querying output modes
2013-09-15T01:02:23.307Z,1379206943.307 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:02:25.318Z,1379206945.318 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:25.318Z,1379206945.318 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:02:25.318Z,1379206945.318 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:02:27.337Z,1379206947.337 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:29.345Z,1379206949.345 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:02:29.345Z,1379206949.345 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:02:31.348Z,1379206951.348 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:02:31.348Z,1379206951.348 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:02:33.350Z,1379206953.350 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:33.350Z,1379206953.350 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:02:33.351Z,1379206953.351 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:02:35.357Z,1379206955.357 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:35.358Z,1379206955.358 [DVL_micro](INFO): Querying output modes
2013-09-15T01:02:35.358Z,1379206955.358 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:02:37.381Z,1379206957.381 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:37.381Z,1379206957.381 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:02:37.381Z,1379206957.381 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:02:39.392Z,1379206959.392 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:41.404Z,1379206961.404 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:02:41.404Z,1379206961.404 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:02:43.406Z,1379206963.406 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:02:43.407Z,1379206963.407 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:02:45.417Z,1379206965.417 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:45.417Z,1379206965.417 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:02:45.417Z,1379206965.417 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:02:47.428Z,1379206967.428 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:47.428Z,1379206967.428 [DVL_micro](INFO): Querying output modes
2013-09-15T01:02:47.429Z,1379206967.429 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:02:49.435Z,1379206969.435 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:49.436Z,1379206969.436 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:02:49.436Z,1379206969.436 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:02:51.438Z,1379206971.438 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:53.442Z,1379206973.442 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:02:53.442Z,1379206973.442 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:02:55.445Z,1379206975.445 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:02:55.445Z,1379206975.445 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:02:55.642Z,1379206975.642 [Startup:StartupSatComms:B](INFO): Timed out from 2013-09-15T01:01:55.3Z
2013-09-15T01:02:55.642Z,1379206975.642 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-09-15T01:02:55.643Z,1379206975.643 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-09-15T01:02:55.643Z,1379206975.643 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-09-15T01:02:55.643Z,1379206975.643 [Startup:StartupSatComms:B] Stopped
2013-09-15T01:02:55.643Z,1379206975.643 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-09-15T01:02:55.643Z,1379206975.643 [Startup:StartupSatComms] Stopped
2013-09-15T01:02:55.643Z,1379206975.643 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-09-15T01:02:55.644Z,1379206975.644 [Startup](INFO): Completed Startup
2013-09-15T01:02:55.644Z,1379206975.644 [Startup] Stopped
2013-09-15T01:02:55.644Z,1379206975.644 [Startup](INFO): Aggregate::uninitialize Startup
2013-09-15T01:02:55.644Z,1379206975.644 [Startup:A.GoToSurface] Stopped
2013-09-15T01:02:55.644Z,1379206975.644 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-15T01:02:56.043Z,1379206976.043 [MissionManager](IMPORTANT): Started mission Default
2013-09-15T01:02:56.043Z,1379206976.043 [Default] Running Loop=1
2013-09-15T01:02:56.043Z,1379206976.043 [Default](INFO): Aggregate::initialize Default
2013-09-15T01:02:56.043Z,1379206976.043 [Default:D.SetSpeed] Running Loop=1
2013-09-15T01:02:56.043Z,1379206976.043 [Default:D.SetSpeed](DEBUG): Initialize.
2013-09-15T01:02:56.044Z,1379206976.044 [Default:E.GoToSurface] Running Loop=1
2013-09-15T01:02:56.044Z,1379206976.044 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-15T01:02:56.044Z,1379206976.044 [Default:Iridium] Running Loop=1
2013-09-15T01:02:56.044Z,1379206976.044 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-09-15T01:02:56.044Z,1379206976.044 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-09-15T01:02:56.044Z,1379206976.044 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-09-15T01:02:56.044Z,1379206976.044 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-09-15T01:02:56.044Z,1379206976.044 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-15T01:02:56.045Z,1379206976.045 [Default:E.GoToSurface] Running Loop=1
2013-09-15T01:02:56.050Z,1379206976.050 [Default:D.SetSpeed] Running Loop=1
2013-09-15T01:02:56.056Z,1379206976.056 [Default:CallIridium] Running Loop=1
2013-09-15T01:02:56.056Z,1379206976.056 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-09-15T01:02:56.056Z,1379206976.056 [Default:CallIridium:A] Running Loop=1
2013-09-15T01:02:56.058Z,1379206976.058 [Default:CallIridium:A] Stopped
2013-09-15T01:02:56.058Z,1379206976.058 [Default:CallIridium:B] Running Loop=1
2013-09-15T01:02:56.058Z,1379206976.058 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-09-15T01:02:56.064Z,1379206976.064 [Default:Iridium:B.GoToSurface] Stopped
2013-09-15T01:02:56.064Z,1379206976.064 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-15T01:02:56.064Z,1379206976.064 [Default:Iridium:Read_Iridium] Running Loop=1
2013-09-15T01:02:56.064Z,1379206976.064 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-09-15T01:02:56.077Z,1379206976.077 [Default:GPS] Running Loop=1
2013-09-15T01:02:56.077Z,1379206976.077 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-09-15T01:02:56.077Z,1379206976.077 [Default:GPS:A.SetSpeed] Running Loop=1
2013-09-15T01:02:56.077Z,1379206976.077 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-09-15T01:02:56.077Z,1379206976.077 [Default:GPS:B.GoToSurface] Running Loop=1
2013-09-15T01:02:56.078Z,1379206976.078 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-15T01:02:56.091Z,1379206976.091 [Default:GPS:B.GoToSurface] Stopped
2013-09-15T01:02:56.092Z,1379206976.092 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-15T01:02:56.092Z,1379206976.092 [Default:GPS:Read_GPS] Running Loop=1
2013-09-15T01:02:56.092Z,1379206976.092 [Default:GPS:A.SetSpeed] Running Loop=1
2013-09-15T01:02:56.455Z,1379206976.455 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-09-15T01:02:56.457Z,1379206976.457 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-09-15T01:02:57.452Z,1379206977.452 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:57.452Z,1379206977.452 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:02:57.452Z,1379206977.452 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:02:59.459Z,1379206979.459 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:02:59.459Z,1379206979.459 [DVL_micro](INFO): Querying output modes
2013-09-15T01:02:59.459Z,1379206979.459 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:03:01.466Z,1379206981.466 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:01.466Z,1379206981.466 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:03:01.466Z,1379206981.466 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:03:03.469Z,1379206983.469 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:05.477Z,1379206985.477 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:03:05.477Z,1379206985.477 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:03:07.480Z,1379206987.480 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:03:07.480Z,1379206987.480 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:03:09.490Z,1379206989.490 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:09.491Z,1379206989.491 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:03:09.491Z,1379206989.491 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:03:11.498Z,1379206991.498 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:11.498Z,1379206991.498 [DVL_micro](INFO): Querying output modes
2013-09-15T01:03:11.498Z,1379206991.498 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:03:13.505Z,1379206993.505 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:13.505Z,1379206993.505 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:03:13.505Z,1379206993.505 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:03:15.512Z,1379206995.512 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:17.524Z,1379206997.524 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:03:17.524Z,1379206997.524 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:03:19.526Z,1379206999.526 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:03:19.527Z,1379206999.527 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:03:21.529Z,1379207001.529 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:21.529Z,1379207001.529 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:03:21.529Z,1379207001.529 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:03:23.540Z,1379207003.540 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:23.540Z,1379207003.540 [DVL_micro](INFO): Querying output modes
2013-09-15T01:03:23.540Z,1379207003.540 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:03:25.551Z,1379207005.551 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:25.552Z,1379207005.552 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:03:25.552Z,1379207005.552 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:03:27.554Z,1379207007.554 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:29.562Z,1379207009.562 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:03:29.562Z,1379207009.562 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:03:31.565Z,1379207011.565 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:03:31.565Z,1379207011.565 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:03:33.572Z,1379207013.572 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:33.572Z,1379207013.572 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:03:33.572Z,1379207013.572 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:03:35.579Z,1379207015.579 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:35.579Z,1379207015.579 [DVL_micro](INFO): Querying output modes
2013-09-15T01:03:35.579Z,1379207015.579 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:03:37.586Z,1379207017.586 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:37.586Z,1379207017.586 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:03:37.586Z,1379207017.586 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:03:39.589Z,1379207019.589 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:41.601Z,1379207021.601 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:03:41.601Z,1379207021.601 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:03:43.604Z,1379207023.604 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:03:43.604Z,1379207023.604 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:03:45.614Z,1379207025.614 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:45.615Z,1379207025.615 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:03:45.615Z,1379207025.615 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:03:47.622Z,1379207027.622 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:47.622Z,1379207027.622 [DVL_micro](INFO): Querying output modes
2013-09-15T01:03:47.622Z,1379207027.622 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:03:49.633Z,1379207029.633 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:49.633Z,1379207029.633 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:03:49.633Z,1379207029.633 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:03:51.636Z,1379207031.636 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:53.640Z,1379207033.640 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:03:53.640Z,1379207033.640 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:03:55.642Z,1379207035.642 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:03:55.643Z,1379207035.643 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:03:57.653Z,1379207037.653 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:57.653Z,1379207037.653 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:03:57.653Z,1379207037.653 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:03:59.664Z,1379207039.664 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:03:59.664Z,1379207039.664 [DVL_micro](INFO): Querying output modes
2013-09-15T01:03:59.665Z,1379207039.665 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:04:01.671Z,1379207041.671 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:01.671Z,1379207041.671 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:04:01.672Z,1379207041.672 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:04:03.686Z,1379207043.686 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:05.694Z,1379207045.694 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:04:05.694Z,1379207045.694 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:04:07.697Z,1379207047.697 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:04:07.697Z,1379207047.697 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:04:09.704Z,1379207049.704 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:09.704Z,1379207049.704 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:04:09.704Z,1379207049.704 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:04:11.707Z,1379207051.707 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:11.707Z,1379207051.707 [DVL_micro](INFO): Querying output modes
2013-09-15T01:04:11.707Z,1379207051.707 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:04:13.718Z,1379207053.718 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:13.718Z,1379207053.718 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:04:13.718Z,1379207053.718 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:04:15.729Z,1379207055.729 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:17.733Z,1379207057.733 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:04:17.733Z,1379207057.733 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:04:19.736Z,1379207059.736 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:04:19.736Z,1379207059.736 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:04:21.738Z,1379207061.738 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:21.739Z,1379207061.739 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:04:21.739Z,1379207061.739 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:04:23.750Z,1379207063.750 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:23.750Z,1379207063.750 [DVL_micro](INFO): Querying output modes
2013-09-15T01:04:23.750Z,1379207063.750 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:04:25.753Z,1379207065.753 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:25.753Z,1379207065.753 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:04:25.754Z,1379207065.754 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:04:27.796Z,1379207067.796 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:29.808Z,1379207069.808 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:04:29.808Z,1379207069.808 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:04:31.810Z,1379207071.810 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:04:31.811Z,1379207071.811 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:04:33.813Z,1379207073.813 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:33.813Z,1379207073.813 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:04:33.813Z,1379207073.813 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:04:35.824Z,1379207075.824 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:35.824Z,1379207075.824 [DVL_micro](INFO): Querying output modes
2013-09-15T01:04:35.825Z,1379207075.825 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:04:37.831Z,1379207077.831 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:37.831Z,1379207077.831 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:04:37.832Z,1379207077.832 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:04:39.838Z,1379207079.838 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:41.846Z,1379207081.846 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:04:41.846Z,1379207081.846 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:04:43.849Z,1379207083.849 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:04:43.849Z,1379207083.849 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:04:45.852Z,1379207085.852 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:45.852Z,1379207085.852 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:04:45.852Z,1379207085.852 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:04:47.855Z,1379207087.855 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:47.855Z,1379207087.855 [DVL_micro](INFO): Querying output modes
2013-09-15T01:04:47.855Z,1379207087.855 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:04:49.858Z,1379207089.858 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:49.858Z,1379207089.858 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:04:49.858Z,1379207089.858 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:04:51.861Z,1379207091.861 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:53.873Z,1379207093.873 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:04:53.873Z,1379207093.873 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:04:55.876Z,1379207095.876 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:04:55.876Z,1379207095.876 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:04:57.886Z,1379207097.886 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:57.887Z,1379207097.887 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:04:57.887Z,1379207097.887 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:04:58.921Z,1379207098.921 [CBIT](INFO): Clearing failed count for component AHRS_sp3003D
2013-09-15T01:04:58.922Z,1379207098.922 [AHRS_sp3003D] No Fault, FailCount= 5
2013-09-15T01:04:58.935Z,1379207098.935 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:04:59.898Z,1379207099.898 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:04:59.898Z,1379207099.898 [DVL_micro](INFO): Querying output modes
2013-09-15T01:04:59.898Z,1379207099.898 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:05:00.070Z,1379207100.070 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:05:00.070Z,1379207100.070 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:05:00.070Z,1379207100.070 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-09-15T01:05:00.070Z,1379207100.070 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:05:00.117Z,1379207100.117 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:05:00.138Z,1379207100.138 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:05:01.378Z,1379207101.378 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:05:01.378Z,1379207101.378 [AHRS_sp3003D] No Fault, FailCount= 1
2013-09-15T01:05:01.736Z,1379207101.736 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:05:01.905Z,1379207101.905 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:01.905Z,1379207101.905 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:05:01.905Z,1379207101.905 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:05:02.818Z,1379207102.818 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:05:02.818Z,1379207102.818 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA40BFF
2013-09-15T01:05:02.819Z,1379207102.819 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:05:02.819Z,1379207102.819 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2013-09-15T01:05:02.819Z,1379207102.819 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:05:02.896Z,1379207102.896 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:05:03.106Z,1379207103.106 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:05:03.912Z,1379207103.912 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:04.357Z,1379207104.357 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:05:04.357Z,1379207104.357 [AHRS_sp3003D] No Fault, FailCount= 2
2013-09-15T01:05:04.705Z,1379207104.705 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:05:05.622Z,1379207105.622 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:05:05.623Z,1379207105.623 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-09-15T01:05:05.623Z,1379207105.623 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:05:05.623Z,1379207105.623 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2013-09-15T01:05:05.623Z,1379207105.623 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:05:05.657Z,1379207105.657 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:05:05.906Z,1379207105.906 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:05:05.920Z,1379207105.920 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:05:05.920Z,1379207105.920 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:05:07.300Z,1379207107.300 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:05:07.300Z,1379207107.300 [AHRS_sp3003D] No Fault, FailCount= 3
2013-09-15T01:05:07.661Z,1379207107.661 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:05:07.922Z,1379207107.922 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:05:07.923Z,1379207107.923 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:05:08.575Z,1379207108.575 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:05:08.575Z,1379207108.575 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-09-15T01:05:08.575Z,1379207108.575 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:05:08.575Z,1379207108.575 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2013-09-15T01:05:08.576Z,1379207108.576 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:05:08.629Z,1379207108.629 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:05:08.860Z,1379207108.860 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:05:09.929Z,1379207109.929 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:09.929Z,1379207109.929 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:05:09.929Z,1379207109.929 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:05:10.602Z,1379207110.602 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:05:10.602Z,1379207110.602 [AHRS_sp3003D] No Fault, FailCount= 4
2013-09-15T01:05:10.616Z,1379207110.616 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:05:11.536Z,1379207111.536 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:05:11.536Z,1379207111.536 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-09-15T01:05:11.536Z,1379207111.536 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:05:11.536Z,1379207111.536 [AHRS_sp3003D] Hardware Fault, FailCount= 5
2013-09-15T01:05:11.536Z,1379207111.536 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:05:11.583Z,1379207111.583 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:05:11.583Z,1379207111.583 [CBIT](CRITICAL): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:05:11.815Z,1379207111.815 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:05:11.932Z,1379207111.932 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:11.933Z,1379207111.933 [DVL_micro](INFO): Querying output modes
2013-09-15T01:05:11.933Z,1379207111.933 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:05:13.943Z,1379207113.943 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:13.943Z,1379207113.943 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:05:13.944Z,1379207113.944 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:05:15.946Z,1379207115.946 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:17.958Z,1379207117.958 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:05:17.958Z,1379207117.958 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:05:19.961Z,1379207119.961 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:05:19.961Z,1379207119.961 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:05:21.965Z,1379207121.965 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:21.965Z,1379207121.965 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:05:21.965Z,1379207121.965 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:05:23.967Z,1379207123.967 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:23.967Z,1379207123.967 [DVL_micro](INFO): Querying output modes
2013-09-15T01:05:23.967Z,1379207123.967 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:05:25.974Z,1379207125.974 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:25.974Z,1379207125.974 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:05:25.974Z,1379207125.974 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:05:27.985Z,1379207127.985 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:29.999Z,1379207129.999 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:05:29.999Z,1379207129.999 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:05:31.880Z,1379207131.880 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/tank_weight.xml
2013-09-15T01:05:31.880Z,1379207131.880 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_weight.xml
2013-09-15T01:05:31.921Z,1379207131.921 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitHiCC = 0.000955 n/a
2013-09-15T01:05:31.924Z,1379207131.924 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitLoCC = 0.000080 n/a
2013-09-15T01:05:31.926Z,1379207131.926 [tank_weight:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2013-09-15T01:05:31.933Z,1379207131.933 [tank_weight:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2013-09-15T01:05:31.942Z,1379207131.942 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2013-09-15T01:05:32.004Z,1379207132.004 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:05:32.004Z,1379207132.004 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:05:32.102Z,1379207132.102 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUS = 0 bool
2013-09-15T01:05:32.105Z,1379207132.105 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2013-09-15T01:05:32.109Z,1379207132.109 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSminPitch = -60.000000 arcdeg
2013-09-15T01:05:32.112Z,1379207132.112 [MissionManager](INFO): DefineArg tank_weight:Science.SampleRSSI = 1 bool
2013-09-15T01:05:32.114Z,1379207132.114 [MissionManager](INFO): DefineArg tank_weight:Science.SampleADCP = 1 bool
2013-09-15T01:05:32.117Z,1379207132.117 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectChlActive = 0 bool
2013-09-15T01:05:32.120Z,1379207132.120 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectNO3Active = 0 bool
2013-09-15T01:05:32.123Z,1379207132.123 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectRSSIActive = 0 bool
2013-09-15T01:05:32.126Z,1379207132.126 [MissionManager](INFO): DefineArg tank_weight:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2013-09-15T01:05:32.128Z,1379207132.128 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrent = 0 bool
2013-09-15T01:05:32.132Z,1379207132.132 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMinDepth = 2.000000 m
2013-09-15T01:05:32.135Z,1379207132.135 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMaxDepth = 5.000000 m
2013-09-15T01:05:32.138Z,1379207132.138 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledAanderaaO2 = 0.000000 n/a
2013-09-15T01:05:32.142Z,1379207132.142 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledNeilBrown = 0.000000 n/a
2013-09-15T01:05:32.145Z,1379207132.145 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledTurbulence_NPS = 0.000000 n/a
2013-09-15T01:05:32.149Z,1379207132.149 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledWetLabsBB2FL = 0.000000 n/a
2013-09-15T01:05:32.152Z,1379207132.152 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledDVL = 1.000000 n/a
2013-09-15T01:05:32.156Z,1379207132.156 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledISUS = 0.000000 n/a
2013-09-15T01:05:32.159Z,1379207132.159 [MissionManager](INFO): DefineArg tank_weight:Science.HFRadarModelActive = 0 bool
2013-09-15T01:05:32.162Z,1379207132.162 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChl = 0.000000 ug/l
2013-09-15T01:05:32.188Z,1379207132.188 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlDepth = 0.000000 m
2013-09-15T01:05:32.191Z,1379207132.191 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLatitude = nan arcdeg
2013-09-15T01:05:32.229Z,1379207132.229 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLongitude = nan arcdeg
2013-09-15T01:05:32.235Z,1379207132.235 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3 = 0.000000 umol/l
2013-09-15T01:05:32.238Z,1379207132.238 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Depth = 0.000000 m
2013-09-15T01:05:32.257Z,1379207132.257 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Latitude = nan arcdeg
2013-09-15T01:05:32.273Z,1379207132.273 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Longitude = nan arcdeg
2013-09-15T01:05:32.281Z,1379207132.281 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSI = 0.000000 dB
2013-09-15T01:05:32.292Z,1379207132.292 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSIDepth = 0.000000 m
2013-09-15T01:05:32.295Z,1379207132.295 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILatitude = nan arcdeg
2013-09-15T01:05:32.308Z,1379207132.308 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILongitude = nan arcdeg
2013-09-15T01:05:32.311Z,1379207132.311 [MissionManager](INFO): DefineOutput tank_weight:Science.eastwardSurfaceCurrent = nan m/s
2013-09-15T01:05:32.319Z,1379207132.319 [MissionManager](INFO): DefineOutput tank_weight:Science.northwardSurfaceCurrent = nan m/s
2013-09-15T01:05:32.342Z,1379207132.342 [tank_weight:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-15T01:05:32.353Z,1379207132.353 [tank_weight:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-15T01:05:32.363Z,1379207132.363 [tank_weight:Science:PeakDetectRSSI:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-15T01:05:32.394Z,1379207132.394 [MissionManager](INFO): RedefineArg tank_weight:Science.SampleISUS = 1 bool
2013-09-15T01:05:32.395Z,1379207132.395 [tank_weight:D:A.SetSpeed](DEBUG): Construct.
2013-09-15T01:05:32.407Z,1379207132.407 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Construct Buoyancy.
2013-09-15T01:05:32.410Z,1379207132.410 [tank_weight:D:BuoyancyLo:B.Pitch](DEBUG): Construct.
2013-09-15T01:05:32.421Z,1379207132.421 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Construct Wait.
2013-09-15T01:05:32.423Z,1379207132.423 [tank_weight:D:BuoyancyHi:A.Buoyancy](DEBUG): Construct Buoyancy.
2013-09-15T01:05:32.426Z,1379207132.426 [tank_weight:D:BuoyancyHi:B.Pitch](DEBUG): Construct.
2013-09-15T01:05:32.432Z,1379207132.432 [tank_weight:D:BuoyancyHi:C.Wait](DEBUG): Construct Wait.
2013-09-15T01:05:32.445Z,1379207132.445 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Trigger="Tethys/Trigger" 
       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="tank_weight">

    <DefineArg Name="BuoyancyLimitHiCC"><Control:VerticalControl.buoyancyLimitHiCC/></DefineArg>

    <DefineArg Name="BuoyancyLimitLoCC"><Control:VerticalControl.buoyancyLimitLoCC/></DefineArg>

    <Timeout Duration="P75M"/>

    <Guidance:AltitudeEnvelope RunIn="Parallel">
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Units:meter/><Value>0</Value></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:DepthEnvelope RunIn="Parallel">
        <Setting><Guidance:DepthEnvelope.minDepth/><Units:meter/><Value>0</Value></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Units:meter/><Value>15</Value></Setting>
    </Guidance:DepthEnvelope>

    <Insert Filename="Insert/Science.xml">
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
    </Insert>

    <Aggregate>

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
        </Guidance:SetSpeed>

        <Aggregate Id="BuoyancyLo">

            <Guidance:Buoyancy RunIn="Parallel">
                <Setting><Guidance:Buoyancy.position/><Arg Name="BuoyancyLimitLoCC"/></Setting>
            </Guidance:Buoyancy>

            <Guidance:Pitch RunIn="Parallel">
                <Setting><Guidance:Pitch.massPosition/><Units:meter/><Value>0</Value></Setting>
                <Setting><Guidance:Pitch.depth/><Units:meter/><Value>15</Value></Setting>
            </Guidance:Pitch>

            <Guidance:Wait RunIn="Sequence">
                <Setting><Guidance:Wait.duration/><Units:minute/><Value>65</Value></Setting>
            </Guidance:Wait>

        </Aggregate>

        <Aggregate Id="BuoyancyHi">

            <Guidance:Buoyancy RunIn="Parallel">
                <Setting><Guidance:Buoyancy.position/><Arg Name="BuoyancyLimitHiCC"/></Setting>
            </Guidance:Buoyancy>

            <Guidance:Pitch RunIn="Parallel">
                <Setting><Guidance:Pitch.massPosition/><Units:meter/><Value>0</Value></Setting>
                <Setting><Guidance:Pitch.depth/><Units:meter/><Value>15</Value></Setting>
            </Guidance:Pitch>

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

        </Aggregate>

    </Aggregate>

</Mission>


2013-09-15T01:05:32.448Z,1379207132.448 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/tank_weight.xml
2013-09-15T01:05:32.659Z,1379207132.659 [Default] Stopped
2013-09-15T01:05:32.659Z,1379207132.659 [Default](INFO): Aggregate::uninitialize Default
2013-09-15T01:05:32.659Z,1379207132.659 [Default:GPS] Stopped
2013-09-15T01:05:32.659Z,1379207132.659 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-09-15T01:05:32.659Z,1379207132.659 [Default:GPS:A.SetSpeed] Stopped
2013-09-15T01:05:32.659Z,1379207132.659 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-09-15T01:05:32.659Z,1379207132.659 [Default:GPS:Read_GPS] Stopped
2013-09-15T01:05:32.659Z,1379207132.659 [Default:Iridium] Stopped
2013-09-15T01:05:32.660Z,1379207132.660 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-09-15T01:05:32.660Z,1379207132.660 [Default:Iridium:A.SetSpeed] Stopped
2013-09-15T01:05:32.660Z,1379207132.660 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-09-15T01:05:32.660Z,1379207132.660 [Default:Iridium:Read_Iridium] Stopped
2013-09-15T01:05:32.660Z,1379207132.660 [Default:CallIridium] Stopped
2013-09-15T01:05:32.660Z,1379207132.660 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-09-15T01:05:32.660Z,1379207132.660 [Default:CallIridium:B] Stopped
2013-09-15T01:05:32.660Z,1379207132.660 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-09-15T01:05:32.660Z,1379207132.660 [Default:D.SetSpeed] Stopped
2013-09-15T01:05:32.661Z,1379207132.661 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-09-15T01:05:32.661Z,1379207132.661 [Default:E.GoToSurface] Stopped
2013-09-15T01:05:32.661Z,1379207132.661 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-15T01:05:32.661Z,1379207132.661 [MissionManager](IMPORTANT): Started mission tank_weight
2013-09-15T01:05:32.661Z,1379207132.661 [tank_weight] Running Loop=1
2013-09-15T01:05:32.661Z,1379207132.661 [tank_weight](INFO): Aggregate::initialize tank_weight
2013-09-15T01:05:32.661Z,1379207132.661 [tank_weight:A.AltitudeEnvelope] Running Loop=1
2013-09-15T01:05:32.661Z,1379207132.661 [tank_weight:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2013-09-15T01:05:32.661Z,1379207132.661 [tank_weight:B.DepthEnvelope] Running Loop=1
2013-09-15T01:05:32.662Z,1379207132.662 [tank_weight:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science](INFO): Aggregate::initialize tank_weight:Science
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:A] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:B] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:C] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:D] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:E] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:F] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:G] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:H] Running Loop=1
2013-09-15T01:05:32.663Z,1379207132.663 [tank_weight:Science:I] Running Loop=1
2013-09-15T01:05:32.664Z,1379207132.664 [tank_weight:D] Running Loop=1
2013-09-15T01:05:32.664Z,1379207132.664 [tank_weight:D](INFO): Aggregate::initialize tank_weight:D
2013-09-15T01:05:32.664Z,1379207132.664 [tank_weight:D:A.SetSpeed] Running Loop=1
2013-09-15T01:05:32.664Z,1379207132.664 [tank_weight:D:A.SetSpeed](DEBUG): Initialize.
2013-09-15T01:05:32.696Z,1379207132.696 [tank_weight:D:BuoyancyLo] Running Loop=1
2013-09-15T01:05:32.697Z,1379207132.697 [tank_weight:D:BuoyancyLo](INFO): Aggregate::initialize tank_weight:D:BuoyancyLo
2013-09-15T01:05:32.697Z,1379207132.697 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1
2013-09-15T01:05:32.697Z,1379207132.697 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2013-09-15T01:05:32.697Z,1379207132.697 [tank_weight:D:BuoyancyLo:B.Pitch] Running Loop=1
2013-09-15T01:05:32.697Z,1379207132.697 [tank_weight:D:BuoyancyLo:B.Pitch](DEBUG): Initialize.
2013-09-15T01:05:32.697Z,1379207132.697 [tank_weight:D:BuoyancyLo:C.Wait] Running Loop=1
2013-09-15T01:05:32.697Z,1379207132.697 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Initialize Wait Component.
2013-09-15T01:05:32.702Z,1379207132.702 [tank_weight:D:BuoyancyLo:B.Pitch] Running Loop=1
2013-09-15T01:05:32.707Z,1379207132.707 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1
2013-09-15T01:05:32.712Z,1379207132.712 [tank_weight:D:A.SetSpeed] Running Loop=1
2013-09-15T01:05:32.717Z,1379207132.717 [tank_weight:Science] Running Loop=1
2013-09-15T01:05:32.718Z,1379207132.718 [tank_weight:Science:H] Running Loop=1
2013-09-15T01:05:32.719Z,1379207132.719 [tank_weight:Science:H](DEBUG): Initialize ReadDataComponent to sense DVL_micro.Beam1RSSI
2013-09-15T01:05:32.720Z,1379207132.720 [tank_weight:Science:G] Running Loop=1
2013-09-15T01:05:32.722Z,1379207132.722 [tank_weight:Science:G](DEBUG): Initialize ReadDataComponent to sense DVL_micro.AdcpXWaterVelocity
2013-09-15T01:05:32.723Z,1379207132.723 [tank_weight:B.DepthEnvelope] Running Loop=1
2013-09-15T01:05:32.728Z,1379207132.728 [tank_weight:A.AltitudeEnvelope] Running Loop=1
2013-09-15T01:05:34.014Z,1379207134.014 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:34.015Z,1379207134.015 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:05:34.015Z,1379207134.015 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:05:34.251Z,1379207134.251 [tank_weight:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2013-09-15T01:05:36.022Z,1379207136.022 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:36.022Z,1379207136.022 [DVL_micro](INFO): Querying output modes
2013-09-15T01:05:36.022Z,1379207136.022 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:05:38.033Z,1379207138.033 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:38.033Z,1379207138.033 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:05:38.033Z,1379207138.033 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:05:40.036Z,1379207140.036 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:42.040Z,1379207142.040 [DVL_micro](INFO): RSSI requested
2013-09-15T01:05:42.040Z,1379207142.040 [DVL_micro](INFO): ADCP requested
2013-09-15T01:05:42.040Z,1379207142.040 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:05:42.040Z,1379207142.040 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:05:44.042Z,1379207144.042 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:05:44.043Z,1379207144.043 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:05:46.053Z,1379207146.053 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:46.053Z,1379207146.053 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:05:46.054Z,1379207146.054 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:05:48.060Z,1379207148.060 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:48.060Z,1379207148.060 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:05:48.061Z,1379207148.061 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:05:50.071Z,1379207150.071 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:50.071Z,1379207150.071 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:05:50.072Z,1379207150.072 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:05:52.074Z,1379207152.074 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:52.075Z,1379207152.075 [DVL_micro](INFO): Querying output modes
2013-09-15T01:05:52.075Z,1379207152.075 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:05:54.078Z,1379207154.078 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:54.078Z,1379207154.078 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:05:54.078Z,1379207154.078 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:05:56.097Z,1379207156.097 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:05:58.127Z,1379207158.127 [DVL_micro](INFO): RSSI requested
2013-09-15T01:05:58.127Z,1379207158.127 [DVL_micro](INFO): ADCP requested
2013-09-15T01:05:58.128Z,1379207158.128 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:05:58.128Z,1379207158.128 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:05:58.249Z,1379207158.249 [CommandLine](IMPORTANT): got command report periodic 1.000000 platform_mass_position
2013-09-15T01:05:58.322Z,1379207158.322 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:05:59.479Z,1379207159.479 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:00.131Z,1379207160.131 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:06:00.132Z,1379207160.132 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:06:00.684Z,1379207160.684 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:02.019Z,1379207162.019 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:02.134Z,1379207162.134 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:02.134Z,1379207162.134 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:06:02.134Z,1379207162.134 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:06:03.077Z,1379207163.077 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:04.145Z,1379207164.145 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:04.145Z,1379207164.145 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:06:04.146Z,1379207164.146 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:06:04.291Z,1379207164.291 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:05.481Z,1379207165.481 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:06.156Z,1379207166.156 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:06.157Z,1379207166.157 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:06:06.157Z,1379207166.157 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:06:06.686Z,1379207166.686 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:07.893Z,1379207167.893 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:08.167Z,1379207168.167 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:08.168Z,1379207168.168 [DVL_micro](INFO): Querying output modes
2013-09-15T01:06:08.168Z,1379207168.168 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:06:09.111Z,1379207169.111 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:10.175Z,1379207170.175 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:10.175Z,1379207170.175 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:06:10.175Z,1379207170.175 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:06:10.288Z,1379207170.288 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:11.485Z,1379207171.485 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:12.178Z,1379207172.178 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:12.700Z,1379207172.700 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:13.886Z,1379207173.886 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:14.185Z,1379207174.185 [DVL_micro](INFO): RSSI requested
2013-09-15T01:06:14.186Z,1379207174.186 [DVL_micro](INFO): ADCP requested
2013-09-15T01:06:14.186Z,1379207174.186 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:06:14.186Z,1379207174.186 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:06:15.096Z,1379207175.096 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:16.188Z,1379207176.188 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:06:16.189Z,1379207176.189 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:06:16.290Z,1379207176.290 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:17.483Z,1379207177.483 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:18.191Z,1379207178.191 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:18.191Z,1379207178.191 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:06:18.191Z,1379207178.191 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:06:18.709Z,1379207178.709 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:19.879Z,1379207179.879 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:20.198Z,1379207180.198 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:20.198Z,1379207180.198 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:06:20.198Z,1379207180.198 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:06:21.129Z,1379207181.129 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:22.208Z,1379207182.208 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:22.209Z,1379207182.209 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:06:22.209Z,1379207182.209 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:06:22.291Z,1379207182.291 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:23.493Z,1379207183.493 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:24.221Z,1379207184.221 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:24.221Z,1379207184.221 [DVL_micro](INFO): Querying output modes
2013-09-15T01:06:24.221Z,1379207184.221 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:06:24.694Z,1379207184.694 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:25.885Z,1379207185.885 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:26.228Z,1379207186.228 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:26.228Z,1379207186.228 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:06:26.228Z,1379207186.228 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:06:27.090Z,1379207187.090 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:28.231Z,1379207188.231 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:28.289Z,1379207188.289 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:29.482Z,1379207189.482 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:30.303Z,1379207190.303 [DVL_micro](INFO): RSSI requested
2013-09-15T01:06:30.304Z,1379207190.304 [DVL_micro](INFO): ADCP requested
2013-09-15T01:06:30.304Z,1379207190.304 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:06:30.304Z,1379207190.304 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:06:30.688Z,1379207190.688 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:31.878Z,1379207191.878 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:32.332Z,1379207192.332 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:06:32.332Z,1379207192.332 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:06:33.100Z,1379207193.100 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:34.284Z,1379207194.284 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:34.336Z,1379207194.336 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:34.336Z,1379207194.336 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:06:34.336Z,1379207194.336 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:06:35.390Z,1379207195.390 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction -1.000000 centimeter
2013-09-15T01:06:35.392Z,1379207195.392 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2013-09-15T01:06:35.484Z,1379207195.484 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:35.488Z,1379207195.488 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-09-15T01:06:36.339Z,1379207196.339 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:36.339Z,1379207196.339 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:06:36.339Z,1379207196.339 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:06:36.721Z,1379207196.721 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:38.078Z,1379207198.078 [Reporter](INFO): platform_mass_position -0.000011 m
2013-09-15T01:06:38.346Z,1379207198.346 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:38.346Z,1379207198.346 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:06:38.347Z,1379207198.347 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:06:39.433Z,1379207199.433 [Reporter](INFO): platform_mass_position -0.000983 m
2013-09-15T01:06:40.357Z,1379207200.357 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:40.357Z,1379207200.357 [DVL_micro](INFO): Querying output modes
2013-09-15T01:06:40.358Z,1379207200.358 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:06:40.651Z,1379207200.651 [Reporter](INFO): platform_mass_position -0.001889 m
2013-09-15T01:06:41.817Z,1379207201.817 [Reporter](INFO): platform_mass_position -0.002754 m
2013-09-15T01:06:42.360Z,1379207202.360 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:42.361Z,1379207202.361 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:06:42.361Z,1379207202.361 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:06:43.030Z,1379207203.030 [Reporter](INFO): platform_mass_position -0.003653 m
2013-09-15T01:06:44.228Z,1379207204.228 [Reporter](INFO): platform_mass_position -0.004543 m
2013-09-15T01:06:44.368Z,1379207204.368 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:45.486Z,1379207205.486 [Reporter](INFO): platform_mass_position -0.005471 m
2013-09-15T01:06:46.375Z,1379207206.375 [DVL_micro](INFO): RSSI requested
2013-09-15T01:06:46.375Z,1379207206.375 [DVL_micro](INFO): ADCP requested
2013-09-15T01:06:46.375Z,1379207206.375 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:06:46.376Z,1379207206.376 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:06:46.608Z,1379207206.608 [Reporter](INFO): platform_mass_position -0.006304 m
2013-09-15T01:06:47.806Z,1379207207.806 [Reporter](INFO): platform_mass_position -0.007195 m
2013-09-15T01:06:48.378Z,1379207208.378 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:06:48.379Z,1379207208.379 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:06:49.140Z,1379207209.140 [Reporter](INFO): platform_mass_position -0.008186 m
2013-09-15T01:06:50.193Z,1379207210.193 [Reporter](INFO): platform_mass_position -0.008971 m
2013-09-15T01:06:50.381Z,1379207210.381 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:50.381Z,1379207210.381 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:06:50.381Z,1379207210.381 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:06:51.548Z,1379207211.548 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:06:52.392Z,1379207212.392 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:52.392Z,1379207212.392 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:06:52.392Z,1379207212.392 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:06:52.554Z,1379207212.554 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:06:53.752Z,1379207213.752 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:06:54.399Z,1379207214.399 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:54.399Z,1379207214.399 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:06:54.399Z,1379207214.399 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:06:54.961Z,1379207214.961 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:06:56.151Z,1379207216.151 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:06:56.410Z,1379207216.410 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:56.410Z,1379207216.410 [DVL_micro](INFO): Querying output modes
2013-09-15T01:06:56.411Z,1379207216.411 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:06:57.373Z,1379207217.373 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:06:58.418Z,1379207218.418 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:06:58.418Z,1379207218.418 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:06:58.418Z,1379207218.418 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:06:58.619Z,1379207218.619 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:06:59.749Z,1379207219.749 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:00.429Z,1379207220.429 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:01.030Z,1379207221.030 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:02.153Z,1379207222.153 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:02.460Z,1379207222.460 [DVL_micro](INFO): RSSI requested
2013-09-15T01:07:02.460Z,1379207222.460 [DVL_micro](INFO): ADCP requested
2013-09-15T01:07:02.460Z,1379207222.460 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:07:02.460Z,1379207222.460 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:07:03.446Z,1379207223.446 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:04.463Z,1379207224.463 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:07:04.463Z,1379207224.463 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:07:04.585Z,1379207224.585 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:05.750Z,1379207225.750 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:06.467Z,1379207226.467 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:06.467Z,1379207226.467 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:07:06.467Z,1379207226.467 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:07:07.032Z,1379207227.032 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:08.278Z,1379207228.278 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:08.469Z,1379207228.469 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:08.469Z,1379207228.469 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:07:08.469Z,1379207228.469 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:07:09.376Z,1379207229.376 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:10.476Z,1379207230.476 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:10.476Z,1379207230.476 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:07:10.476Z,1379207230.476 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:07:10.673Z,1379207230.673 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:11.752Z,1379207231.752 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:12.479Z,1379207232.479 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:12.479Z,1379207232.479 [DVL_micro](INFO): Querying output modes
2013-09-15T01:07:12.479Z,1379207232.479 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:07:13.029Z,1379207233.029 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:14.156Z,1379207234.156 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:14.482Z,1379207234.482 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:14.482Z,1379207234.482 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:07:14.483Z,1379207234.483 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:07:15.378Z,1379207235.378 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:16.493Z,1379207236.493 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:16.590Z,1379207236.590 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:17.749Z,1379207237.749 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:18.505Z,1379207238.505 [DVL_micro](INFO): RSSI requested
2013-09-15T01:07:18.505Z,1379207238.505 [DVL_micro](INFO): ADCP requested
2013-09-15T01:07:18.505Z,1379207238.505 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:07:18.505Z,1379207238.505 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:07:19.026Z,1379207239.026 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:20.184Z,1379207240.184 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:20.508Z,1379207240.508 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:07:20.508Z,1379207240.508 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:07:21.375Z,1379207241.375 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:22.511Z,1379207242.511 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:22.511Z,1379207242.511 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:07:22.511Z,1379207242.511 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:07:22.620Z,1379207242.620 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:23.798Z,1379207243.798 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:24.518Z,1379207244.518 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:24.518Z,1379207244.518 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:07:24.518Z,1379207244.518 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:07:24.984Z,1379207244.984 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:26.150Z,1379207246.150 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:26.525Z,1379207246.525 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:26.525Z,1379207246.525 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:07:26.526Z,1379207246.526 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:07:27.447Z,1379207247.447 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:28.528Z,1379207248.528 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:28.528Z,1379207248.528 [DVL_micro](INFO): Querying output modes
2013-09-15T01:07:28.528Z,1379207248.528 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:07:28.550Z,1379207248.550 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:29.711Z,1379207249.711 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction -2.000000 centimeter
2013-09-15T01:07:29.784Z,1379207249.784 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:30.531Z,1379207250.531 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:30.531Z,1379207250.531 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:07:30.532Z,1379207250.532 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:07:31.120Z,1379207251.120 [Reporter](INFO): platform_mass_position -0.009979 m
2013-09-15T01:07:32.463Z,1379207252.463 [Reporter](INFO): platform_mass_position -0.010333 m
2013-09-15T01:07:32.542Z,1379207252.542 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:33.683Z,1379207253.683 [Reporter](INFO): platform_mass_position -0.011237 m
2013-09-15T01:07:34.575Z,1379207254.575 [DVL_micro](INFO): RSSI requested
2013-09-15T01:07:34.575Z,1379207254.575 [DVL_micro](INFO): ADCP requested
2013-09-15T01:07:34.575Z,1379207254.575 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:07:34.575Z,1379207254.575 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:07:34.873Z,1379207254.873 [Reporter](INFO): platform_mass_position -0.012123 m
2013-09-15T01:07:35.665Z,1379207255.665 [CBIT](CRITICAL): Environmental Failure. Press:14.451184 PSI. Humidity:43%. Temp:22 C. ABORTING MISSION
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight] Stopped
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight](INFO): Aggregate::uninitialize tank_weight
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:A.AltitudeEnvelope] Stopped
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:B.DepthEnvelope] Stopped
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:B.DepthEnvelope](DEBUG): Uninitialize.
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:Science] Stopped
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:Science](INFO): Aggregate::uninitialize tank_weight:Science
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:Science:A] Stopped
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:Science:B] Stopped
2013-09-15T01:07:35.974Z,1379207255.974 [tank_weight:Science:C] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:Science:D] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:Science:E] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:Science:F] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:Science:G] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:Science:H] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:Science:I] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:D] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:D](INFO): Aggregate::uninitialize tank_weight:D
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:D:A.SetSpeed] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:D:A.SetSpeed](DEBUG): Uninitialize.
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:D:BuoyancyLo] Stopped
2013-09-15T01:07:35.975Z,1379207255.975 [tank_weight:D:BuoyancyLo](INFO): Aggregate::uninitialize tank_weight:D:BuoyancyLo
2013-09-15T01:07:35.976Z,1379207255.976 [tank_weight:D:BuoyancyLo:A.Buoyancy] Stopped
2013-09-15T01:07:35.976Z,1379207255.976 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2013-09-15T01:07:35.976Z,1379207255.976 [tank_weight:D:BuoyancyLo:B.Pitch] Stopped
2013-09-15T01:07:35.976Z,1379207255.976 [tank_weight:D:BuoyancyLo:C.Wait] Stopped
2013-09-15T01:07:35.976Z,1379207255.976 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Uninitialize Wait Component.
2013-09-15T01:07:36.113Z,1379207256.113 [Reporter](INFO): platform_mass_position -0.013046 m
2013-09-15T01:07:36.390Z,1379207256.390 [MissionManager](IMPORTANT): Started mission Default
2013-09-15T01:07:36.390Z,1379207256.390 [Default] Running Loop=1
2013-09-15T01:07:36.391Z,1379207256.391 [Default](INFO): Aggregate::initialize Default
2013-09-15T01:07:36.391Z,1379207256.391 [Default:D.SetSpeed] Running Loop=1
2013-09-15T01:07:36.391Z,1379207256.391 [Default:D.SetSpeed](DEBUG): Initialize.
2013-09-15T01:07:36.391Z,1379207256.391 [Default:E.GoToSurface] Running Loop=1
2013-09-15T01:07:36.391Z,1379207256.391 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-15T01:07:36.391Z,1379207256.391 [Default:Iridium] Running Loop=1
2013-09-15T01:07:36.391Z,1379207256.391 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-09-15T01:07:36.392Z,1379207256.392 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-09-15T01:07:36.392Z,1379207256.392 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-09-15T01:07:36.392Z,1379207256.392 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-09-15T01:07:36.392Z,1379207256.392 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-15T01:07:36.393Z,1379207256.393 [Default:CallIridium] Running Loop=1
2013-09-15T01:07:36.394Z,1379207256.394 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-09-15T01:07:36.394Z,1379207256.394 [Default:CallIridium:A] Running Loop=1
2013-09-15T01:07:36.394Z,1379207256.394 [Default:CallIridium:A] Stopped
2013-09-15T01:07:36.395Z,1379207256.395 [Default:CallIridium:B] Running Loop=1
2013-09-15T01:07:36.395Z,1379207256.395 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-09-15T01:07:36.395Z,1379207256.395 [Default:Iridium:B.GoToSurface] Stopped
2013-09-15T01:07:36.396Z,1379207256.396 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-15T01:07:36.396Z,1379207256.396 [Default:Iridium:Read_Iridium] Running Loop=1
2013-09-15T01:07:36.396Z,1379207256.396 [Default:GPS] Running Loop=1
2013-09-15T01:07:36.396Z,1379207256.396 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-09-15T01:07:36.396Z,1379207256.396 [Default:GPS:A.SetSpeed] Running Loop=1
2013-09-15T01:07:36.396Z,1379207256.396 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-09-15T01:07:36.397Z,1379207256.397 [Default:GPS:B.GoToSurface] Running Loop=1
2013-09-15T01:07:36.397Z,1379207256.397 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-15T01:07:36.397Z,1379207256.397 [Default:GPS:B.GoToSurface] Stopped
2013-09-15T01:07:36.398Z,1379207256.398 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-15T01:07:36.398Z,1379207256.398 [Default:GPS:Read_GPS] Running Loop=1
2013-09-15T01:07:36.581Z,1379207256.581 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:07:36.581Z,1379207256.581 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:07:37.337Z,1379207257.337 [Reporter](INFO): platform_mass_position -0.013958 m
2013-09-15T01:07:38.489Z,1379207258.489 [Reporter](INFO): platform_mass_position -0.014812 m
2013-09-15T01:07:38.592Z,1379207258.592 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:38.592Z,1379207258.592 [DVL_micro](INFO): Enabling RSSI output
2013-09-15T01:07:38.592Z,1379207258.592 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2013-09-15T01:07:39.690Z,1379207259.690 [Reporter](INFO): platform_mass_position -0.015701 m
2013-09-15T01:07:40.595Z,1379207260.595 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:40.595Z,1379207260.595 [DVL_micro](INFO): Enabling ADCP output
2013-09-15T01:07:40.595Z,1379207260.595 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2013-09-15T01:07:40.848Z,1379207260.848 [Reporter](INFO): platform_mass_position -0.016561 m
2013-09-15T01:07:42.054Z,1379207262.054 [Reporter](INFO): platform_mass_position -0.017457 m
2013-09-15T01:07:42.606Z,1379207262.606 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:42.606Z,1379207262.606 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:07:42.606Z,1379207262.606 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:07:43.753Z,1379207263.753 [Reporter](INFO): platform_mass_position -0.018719 m
2013-09-15T01:07:44.609Z,1379207264.609 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:44.609Z,1379207264.609 [DVL_micro](INFO): Querying output modes
2013-09-15T01:07:44.609Z,1379207264.609 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:07:45.094Z,1379207265.094 [Reporter](INFO): platform_mass_position -0.019696 m
2013-09-15T01:07:46.225Z,1379207266.225 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:46.616Z,1379207266.616 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:46.616Z,1379207266.616 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:07:46.616Z,1379207266.616 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:07:47.939Z,1379207267.939 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:48.619Z,1379207268.619 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:49.230Z,1379207269.230 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:50.431Z,1379207270.431 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:50.631Z,1379207270.631 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:07:50.631Z,1379207270.631 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:07:52.138Z,1379207272.138 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:52.634Z,1379207272.634 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:07:52.634Z,1379207272.634 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:07:53.428Z,1379207273.428 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:54.634Z,1379207274.634 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:54.637Z,1379207274.637 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:54.637Z,1379207274.637 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:07:54.637Z,1379207274.637 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:07:55.924Z,1379207275.924 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:56.640Z,1379207276.640 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:56.640Z,1379207276.640 [DVL_micro](INFO): Querying output modes
2013-09-15T01:07:56.640Z,1379207276.640 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:07:57.218Z,1379207277.218 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:58.424Z,1379207278.424 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:07:58.643Z,1379207278.643 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:07:58.643Z,1379207278.643 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:07:58.643Z,1379207278.643 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:08:00.115Z,1379207280.115 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:00.646Z,1379207280.646 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:01.425Z,1379207281.425 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:02.587Z,1379207282.587 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:02.658Z,1379207282.658 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:08:02.658Z,1379207282.658 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:08:03.920Z,1379207283.920 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:04.660Z,1379207284.660 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:08:04.661Z,1379207284.661 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:08:05.230Z,1379207285.230 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:06.412Z,1379207286.412 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:06.663Z,1379207286.663 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:06.663Z,1379207286.663 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:08:06.664Z,1379207286.664 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:08:08.119Z,1379207288.119 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:08.670Z,1379207288.670 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:08.670Z,1379207288.670 [DVL_micro](INFO): Querying output modes
2013-09-15T01:08:08.671Z,1379207288.671 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:08:09.425Z,1379207289.425 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:10.595Z,1379207290.595 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:10.677Z,1379207290.677 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:10.678Z,1379207290.678 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:08:10.678Z,1379207290.678 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:08:11.916Z,1379207291.916 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:12.684Z,1379207292.684 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:13.223Z,1379207293.223 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:14.393Z,1379207294.393 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:14.688Z,1379207294.688 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:08:14.688Z,1379207294.688 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:08:16.115Z,1379207296.115 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:16.691Z,1379207296.691 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:08:16.692Z,1379207296.692 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:08:17.421Z,1379207297.421 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:18.591Z,1379207298.591 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:18.702Z,1379207298.702 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:18.702Z,1379207298.702 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:08:18.702Z,1379207298.702 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:08:19.913Z,1379207299.913 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:20.713Z,1379207300.713 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:20.713Z,1379207300.713 [DVL_micro](INFO): Querying output modes
2013-09-15T01:08:20.713Z,1379207300.713 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:08:21.239Z,1379207301.239 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:22.381Z,1379207302.381 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:22.728Z,1379207302.728 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:22.728Z,1379207302.728 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:08:22.729Z,1379207302.729 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:08:24.120Z,1379207304.120 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:24.739Z,1379207304.739 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:25.418Z,1379207305.418 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:26.604Z,1379207306.604 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:26.751Z,1379207306.751 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:08:26.751Z,1379207306.751 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:08:27.913Z,1379207307.913 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:28.754Z,1379207308.754 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:08:28.754Z,1379207308.754 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:08:29.228Z,1379207309.228 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:30.386Z,1379207310.386 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:30.757Z,1379207310.757 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:30.757Z,1379207310.757 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:08:30.757Z,1379207310.757 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:08:32.120Z,1379207312.120 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:32.765Z,1379207312.765 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:32.766Z,1379207312.766 [DVL_micro](INFO): Querying output modes
2013-09-15T01:08:32.766Z,1379207312.766 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:08:33.430Z,1379207313.430 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:34.596Z,1379207314.596 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:34.775Z,1379207314.775 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:34.775Z,1379207314.775 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:08:34.775Z,1379207314.775 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:08:35.914Z,1379207315.914 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:35.925Z,1379207315.925 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 2.000000 centimeter
2013-09-15T01:08:36.786Z,1379207316.786 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:37.272Z,1379207317.272 [Reporter](INFO): platform_mass_position -0.019968 m
2013-09-15T01:08:38.337Z,1379207318.337 [Reporter](INFO): platform_mass_position -0.019896 m
2013-09-15T01:08:38.794Z,1379207318.794 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:08:38.794Z,1379207318.794 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:08:39.515Z,1379207319.515 [Reporter](INFO): platform_mass_position -0.019021 m
2013-09-15T01:08:40.561Z,1379207320.561 [Reporter](INFO): platform_mass_position -0.018251 m
2013-09-15T01:08:40.796Z,1379207320.796 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:08:40.797Z,1379207320.797 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:08:41.759Z,1379207321.759 [Reporter](INFO): platform_mass_position -0.017358 m
2013-09-15T01:08:42.799Z,1379207322.799 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:42.799Z,1379207322.799 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:08:42.799Z,1379207322.799 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:08:42.952Z,1379207322.952 [Reporter](INFO): platform_mass_position -0.016470 m
2013-09-15T01:08:44.665Z,1379207324.665 [Reporter](INFO): platform_mass_position -0.015203 m
2013-09-15T01:08:44.807Z,1379207324.807 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:44.808Z,1379207324.808 [DVL_micro](INFO): Querying output modes
2013-09-15T01:08:44.808Z,1379207324.808 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:08:46.005Z,1379207326.005 [Reporter](INFO): platform_mass_position -0.014206 m
2013-09-15T01:08:46.817Z,1379207326.817 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:46.818Z,1379207326.818 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:08:46.818Z,1379207326.818 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:08:47.191Z,1379207327.191 [Reporter](INFO): platform_mass_position -0.013331 m
2013-09-15T01:08:48.829Z,1379207328.829 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:48.889Z,1379207328.889 [Reporter](INFO): platform_mass_position -0.012066 m
2013-09-15T01:08:50.224Z,1379207330.224 [Reporter](INFO): platform_mass_position -0.011070 m
2013-09-15T01:08:50.836Z,1379207330.836 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:08:50.836Z,1379207330.836 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:08:51.421Z,1379207331.421 [Reporter](INFO): platform_mass_position -0.010185 m
2013-09-15T01:08:52.723Z,1379207332.723 [Reporter](INFO): platform_mass_position -0.009219 m
2013-09-15T01:08:52.839Z,1379207332.839 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:08:52.839Z,1379207332.839 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:08:54.057Z,1379207334.057 [Reporter](INFO): platform_mass_position -0.008230 m
2013-09-15T01:08:54.846Z,1379207334.846 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:54.846Z,1379207334.846 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:08:54.846Z,1379207334.846 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:08:55.255Z,1379207335.255 [Reporter](INFO): platform_mass_position -0.007339 m
2013-09-15T01:08:56.853Z,1379207336.853 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:56.853Z,1379207336.853 [DVL_micro](INFO): Querying output modes
2013-09-15T01:08:56.853Z,1379207336.853 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:08:56.958Z,1379207336.958 [Reporter](INFO): platform_mass_position -0.006072 m
2013-09-15T01:08:58.296Z,1379207338.296 [Reporter](INFO): platform_mass_position -0.005085 m
2013-09-15T01:08:58.860Z,1379207338.860 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:08:58.860Z,1379207338.860 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:08:58.860Z,1379207338.860 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:08:59.482Z,1379207339.482 [Reporter](INFO): platform_mass_position -0.004205 m
2013-09-15T01:09:00.788Z,1379207340.788 [Reporter](INFO): platform_mass_position -0.003237 m
2013-09-15T01:09:00.867Z,1379207340.867 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:02.122Z,1379207342.122 [Reporter](INFO): platform_mass_position -0.002242 m
2013-09-15T01:09:02.885Z,1379207342.885 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:09:02.886Z,1379207342.886 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:09:03.312Z,1379207343.312 [Reporter](INFO): platform_mass_position -0.001356 m
2013-09-15T01:09:04.902Z,1379207344.902 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:09:04.902Z,1379207344.902 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:09:05.018Z,1379207345.018 [Reporter](INFO): platform_mass_position -0.000090 m
2013-09-15T01:09:06.361Z,1379207346.361 [Reporter](INFO): platform_mass_position 0.000903 m
2013-09-15T01:09:06.913Z,1379207346.913 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:06.913Z,1379207346.913 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:09:06.913Z,1379207346.913 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:09:07.546Z,1379207347.546 [Reporter](INFO): platform_mass_position 0.001784 m
2013-09-15T01:09:08.856Z,1379207348.856 [Reporter](INFO): platform_mass_position 0.002757 m
2013-09-15T01:09:08.920Z,1379207348.920 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:08.920Z,1379207348.920 [DVL_micro](INFO): Querying output modes
2013-09-15T01:09:08.920Z,1379207348.920 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:09:10.186Z,1379207350.186 [Reporter](INFO): platform_mass_position 0.003742 m
2013-09-15T01:09:10.923Z,1379207350.923 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:10.923Z,1379207350.923 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:09:10.923Z,1379207350.923 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:09:11.388Z,1379207351.388 [Reporter](INFO): platform_mass_position 0.004628 m
2013-09-15T01:09:12.930Z,1379207352.930 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:13.087Z,1379207353.087 [Reporter](INFO): platform_mass_position 0.005898 m
2013-09-15T01:09:14.421Z,1379207354.421 [Reporter](INFO): platform_mass_position 0.006890 m
2013-09-15T01:09:14.934Z,1379207354.934 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:09:14.934Z,1379207354.934 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:09:15.599Z,1379207355.599 [Reporter](INFO): platform_mass_position 0.007759 m
2013-09-15T01:09:16.924Z,1379207356.924 [Reporter](INFO): platform_mass_position 0.008747 m
2013-09-15T01:09:16.937Z,1379207356.937 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:09:16.937Z,1379207356.937 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:09:18.259Z,1379207358.259 [Reporter](INFO): platform_mass_position 0.009735 m
2013-09-15T01:09:18.947Z,1379207358.947 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:18.947Z,1379207358.947 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:09:18.948Z,1379207358.948 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:09:19.469Z,1379207359.469 [Reporter](INFO): platform_mass_position 0.010633 m
2013-09-15T01:09:20.958Z,1379207360.958 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:20.959Z,1379207360.959 [DVL_micro](INFO): Querying output modes
2013-09-15T01:09:20.959Z,1379207360.959 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:09:21.155Z,1379207361.155 [Reporter](INFO): platform_mass_position 0.011891 m
2013-09-15T01:09:22.493Z,1379207362.493 [Reporter](INFO): platform_mass_position 0.012877 m
2013-09-15T01:09:22.961Z,1379207362.961 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:22.962Z,1379207362.962 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:09:22.962Z,1379207362.962 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:09:23.686Z,1379207363.686 [Reporter](INFO): platform_mass_position 0.013752 m
2013-09-15T01:09:24.982Z,1379207364.982 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:24.986Z,1379207364.986 [Reporter](INFO): platform_mass_position 0.014727 m
2013-09-15T01:09:26.323Z,1379207366.323 [Reporter](INFO): platform_mass_position 0.015725 m
2013-09-15T01:09:26.984Z,1379207366.984 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:09:26.984Z,1379207366.984 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:09:27.509Z,1379207367.509 [Reporter](INFO): platform_mass_position 0.016607 m
2013-09-15T01:09:28.987Z,1379207368.987 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:09:28.987Z,1379207368.987 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:09:29.227Z,1379207369.227 [Reporter](INFO): platform_mass_position 0.017877 m
2013-09-15T01:09:30.559Z,1379207370.559 [Reporter](INFO): platform_mass_position 0.018860 m
2013-09-15T01:09:30.994Z,1379207370.994 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:30.994Z,1379207370.994 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:09:30.994Z,1379207370.994 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:09:31.752Z,1379207371.752 [Reporter](INFO): platform_mass_position 0.019735 m
2013-09-15T01:09:32.922Z,1379207372.922 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:33.005Z,1379207373.005 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:33.005Z,1379207373.005 [DVL_micro](INFO): Querying output modes
2013-09-15T01:09:33.005Z,1379207373.005 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:09:33.936Z,1379207373.936 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:35.012Z,1379207375.012 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:35.012Z,1379207375.012 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:09:35.012Z,1379207375.012 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:09:35.102Z,1379207375.102 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:36.280Z,1379207376.280 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:37.027Z,1379207377.027 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:37.994Z,1379207377.994 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:39.039Z,1379207379.039 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:09:39.039Z,1379207379.039 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:09:39.261Z,1379207379.261 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:40.440Z,1379207380.440 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:41.042Z,1379207381.042 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:09:41.042Z,1379207381.042 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:09:41.743Z,1379207381.743 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:43.005Z,1379207383.005 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:43.049Z,1379207383.049 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:43.049Z,1379207383.049 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:09:43.049Z,1379207383.049 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:09:44.202Z,1379207384.202 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:45.060Z,1379207385.060 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:45.060Z,1379207385.060 [DVL_micro](INFO): Querying output modes
2013-09-15T01:09:45.060Z,1379207385.060 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:09:45.900Z,1379207385.900 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:47.071Z,1379207387.071 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:47.071Z,1379207387.071 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:09:47.071Z,1379207387.071 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:09:47.221Z,1379207387.221 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:48.348Z,1379207388.348 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:49.078Z,1379207389.078 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:49.656Z,1379207389.656 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:50.922Z,1379207390.922 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:51.086Z,1379207391.086 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:09:51.086Z,1379207391.086 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:09:52.106Z,1379207392.106 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:52.848Z,1379207392.848 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.900000 centimeter
2013-09-15T01:09:53.089Z,1379207393.089 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:09:53.089Z,1379207393.089 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:09:53.812Z,1379207393.812 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:55.095Z,1379207395.095 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:55.095Z,1379207395.095 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:09:55.096Z,1379207395.096 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:09:55.672Z,1379207395.672 [Reporter](INFO): platform_mass_position 0.019963 m
2013-09-15T01:09:56.986Z,1379207396.986 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:09:57.106Z,1379207397.106 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:57.107Z,1379207397.107 [DVL_micro](INFO): Querying output modes
2013-09-15T01:09:57.107Z,1379207397.107 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:09:58.009Z,1379207398.009 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:09:59.118Z,1379207399.118 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:09:59.118Z,1379207399.118 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:09:59.118Z,1379207399.118 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:09:59.206Z,1379207399.206 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:00.396Z,1379207400.396 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:01.133Z,1379207401.133 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:10:02.094Z,1379207402.094 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:02.917Z,1379207402.917 [NAL9602](FAULT): GPS failed to acquire within timeout.
2013-09-15T01:10:02.917Z,1379207402.917 [NAL9602] Data Fault, FailCount= 1
2013-09-15T01:10:02.918Z,1379207402.918 [NAL9602](ERROR): Data Fault
2013-09-15T01:10:02.942Z,1379207402.942 [CBIT](ERROR): Data Fault in component: NAL9602
2013-09-15T01:10:03.136Z,1379207403.136 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:10:03.137Z,1379207403.137 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:10:03.314Z,1379207403.314 [NAL9602](INFO): Powering down
2013-09-15T01:10:03.345Z,1379207403.345 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:04.146Z,1379207404.146 [CBIT](INFO): Clearing failed state for component NAL9602
2013-09-15T01:10:04.146Z,1379207404.146 [NAL9602] No Fault, FailCount= 1
2013-09-15T01:10:04.537Z,1379207404.537 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:05.139Z,1379207405.139 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:10:05.140Z,1379207405.140 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-15T01:10:05.735Z,1379207405.735 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:06.937Z,1379207406.937 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:07.150Z,1379207407.150 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:10:07.150Z,1379207407.150 [DVL_micro](INFO): Enabling NQ1 output
2013-09-15T01:10:07.150Z,1379207407.150 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-15T01:10:08.139Z,1379207408.139 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:08.510Z,1379207408.510 [NAL9602](INFO): Powering up NAL9602
2013-09-15T01:10:09.161Z,1379207409.161 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:10:09.161Z,1379207409.161 [DVL_micro](INFO): Querying output modes
2013-09-15T01:10:09.161Z,1379207409.161 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:10:09.339Z,1379207409.339 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:10.542Z,1379207410.542 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:11.168Z,1379207411.168 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:10:11.168Z,1379207411.168 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:10:11.169Z,1379207411.169 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:10:11.735Z,1379207411.735 [CBIT](INFO): Clearing failed count for component AHRS_sp3003D
2013-09-15T01:10:11.735Z,1379207411.735 [AHRS_sp3003D] No Fault, FailCount= 5
2013-09-15T01:10:11.737Z,1379207411.737 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:12.110Z,1379207412.110 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:10:13.179Z,1379207413.179 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:10:13.251Z,1379207413.251 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:10:13.252Z,1379207413.252 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:10:13.252Z,1379207413.252 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-09-15T01:10:13.252Z,1379207413.252 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:10:13.287Z,1379207413.287 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:10:13.288Z,1379207413.288 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:13.315Z,1379207413.315 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:10:14.536Z,1379207414.536 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:10:14.536Z,1379207414.536 [AHRS_sp3003D] No Fault, FailCount= 1
2013-09-15T01:10:14.538Z,1379207414.538 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:14.909Z,1379207414.909 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:10:15.192Z,1379207415.192 [DVL_micro](INFO): pause:Powering down
2013-09-15T01:10:15.827Z,1379207415.827 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:10:15.828Z,1379207415.828 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xB60FFF
2013-09-15T01:10:15.828Z,1379207415.828 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:10:15.828Z,1379207415.828 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2013-09-15T01:10:15.828Z,1379207415.828 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:10:15.854Z,1379207415.854 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:10:15.856Z,1379207415.856 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:15.996Z,1379207415.996 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:10:15.997Z,1379207415.997 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:10:15.997Z,1379207415.997 [DVL_micro](INFO): resume:Powering up
2013-09-15T01:10:15.997Z,1379207415.997 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:10:16.108Z,1379207416.108 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:10:16.947Z,1379207416.947 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:17.345Z,1379207417.345 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:10:17.345Z,1379207417.345 [AHRS_sp3003D] No Fault, FailCount= 2
2013-09-15T01:10:17.710Z,1379207417.710 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:10:18.003Z,1379207418.003 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:10:18.003Z,1379207418.003 [DVL_micro](INFO): Querying output modes
2013-09-15T01:10:18.004Z,1379207418.004 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-15T01:10:18.139Z,1379207418.139 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:18.624Z,1379207418.624 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:10:18.624Z,1379207418.624 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-09-15T01:10:18.624Z,1379207418.624 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:10:18.624Z,1379207418.624 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2013-09-15T01:10:18.624Z,1379207418.624 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:10:18.657Z,1379207418.657 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:10:18.908Z,1379207418.908 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:10:19.049Z,1379207419.049 [NAL9602](INFO): NAL9602 initialized
2013-09-15T01:10:19.339Z,1379207419.339 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:20.006Z,1379207420.006 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:10:20.006Z,1379207420.006 [DVL_micro](INFO): Output Modes: No Response
2013-09-15T01:10:20.006Z,1379207420.006 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-15T01:10:20.157Z,1379207420.157 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:10:20.157Z,1379207420.157 [AHRS_sp3003D] No Fault, FailCount= 3
2013-09-15T01:10:20.511Z,1379207420.511 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:10:20.556Z,1379207420.556 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:21.432Z,1379207421.432 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-15T01:10:21.432Z,1379207421.432 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA409A0
2013-09-15T01:10:21.432Z,1379207421.432 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-15T01:10:21.433Z,1379207421.433 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2013-09-15T01:10:21.433Z,1379207421.433 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-15T01:10:21.461Z,1379207421.461 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-15T01:10:21.708Z,1379207421.708 [AHRS_sp3003D](INFO): Powering down
2013-09-15T01:10:21.855Z,1379207421.855 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:22.013Z,1379207422.013 [DVL_micro](DEBUG): cmdResponse: 
2013-09-15T01:10:22.015Z,1379207422.015 [DVL_micro](INFO): NQ1 requested
2013-09-15T01:10:22.015Z,1379207422.015 [DVL_micro](INFO): Cycling power to configure device.
2013-09-15T01:10:23.107Z,1379207423.107 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-15T01:10:23.107Z,1379207423.107 [AHRS_sp3003D] No Fault, FailCount= 4
2013-09-15T01:10:23.109Z,1379207423.109 [Reporter](INFO): platform_mass_position 0.019030 m
2013-09-15T01:10:23.471Z,1379207423.471 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-15T01:10:24.021Z,1379207424.021 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-15T01:10:24.021Z,1379207424.021 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0