2012-10-04T17:24:01.067Z,1349371441.067 [Supervisor](DEBUG): Initializing supervisor.
2012-10-04T17:24:01.069Z,1349371441.069 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2012-10-04T17:24:01.070Z,1349371441.070 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-10-04T17:24:01.071Z,1349371441.071 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2012-10-04T17:24:01.075Z,1349371441.075 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-10-04T17:24:01.085Z,1349371441.085 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-10-04T17:24:01.086Z,1349371441.086 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2012-10-04T17:24:01.087Z,1349371441.087 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-10-04T17:24:01.087Z,1349371441.088 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-10-04T17:24:01.089Z,1349371441.089 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-10-04T17:24:01.358Z,1349371441.358 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-10-04T17:24:01.359Z,1349371441.359 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-10-04T17:24:01.536Z,1349371441.536 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-10-04T17:24:01.536Z,1349371441.536 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-10-04T17:24:01.620Z,1349371441.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-10-04T17:24:01.621Z,1349371441.621 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-10-04T17:24:01.813Z,1349371441.813 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-10-04T17:24:01.814Z,1349371441.814 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-10-04T17:24:01.943Z,1349371441.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-10-04T17:24:01.943Z,1349371441.943 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-10-04T17:24:02.164Z,1349371442.164 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-10-04T17:24:02.164Z,1349371442.164 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-10-04T17:24:02.328Z,1349371442.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-10-04T17:24:02.329Z,1349371442.329 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-10-04T17:24:02.566Z,1349371442.566 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-10-04T17:24:02.567Z,1349371442.566 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-10-04T17:24:02.662Z,1349371442.662 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-10-04T17:24:02.663Z,1349371442.663 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-10-04T17:24:03.047Z,1349371443.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-10-04T17:24:03.047Z,1349371443.047 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-10-04T17:24:03.158Z,1349371443.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-10-04T17:24:03.159Z,1349371443.159 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-10-04T17:24:03.242Z,1349371443.242 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-10-04T17:24:03.243Z,1349371443.243 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-10-04T17:24:03.349Z,1349371443.349 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-10-04T17:24:03.475Z,1349371443.475 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-10-04T17:24:03.559Z,1349371443.559 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-10-04T17:24:03.657Z,1349371443.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-10-04T17:24:03.755Z,1349371443.755 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-10-04T17:24:03.869Z,1349371443.869 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-10-04T17:24:03.956Z,1349371443.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-10-04T17:24:04.041Z,1349371444.041 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2012-10-04T17:24:04.069Z,1349371444.069 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-10-04T17:24:04.207Z,1349371444.207 [InternalSim] Loaded
2012-10-04T17:24:04.208Z,1349371444.208 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-10-04T17:24:04.208Z,1349371444.208 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-10-04T17:24:04.209Z,1349371444.209 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-10-04T17:24:04.266Z,1349371444.266 [SBIT](DEBUG): Construct Startup Built In Test.
2012-10-04T17:24:04.279Z,1349371444.279 [SBIT] Loaded
2012-10-04T17:24:04.280Z,1349371444.280 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-10-04T17:24:04.281Z,1349371444.281 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-10-04T17:24:04.309Z,1349371444.309 [IBIT] Loaded
2012-10-04T17:24:04.309Z,1349371444.309 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-10-04T17:24:04.312Z,1349371444.312 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-10-04T17:24:04.428Z,1349371444.428 [CBIT] Loaded
2012-10-04T17:24:04.429Z,1349371444.429 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-10-04T17:24:04.429Z,1349371444.429 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-10-04T17:24:04.430Z,1349371444.430 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-10-04T17:24:04.572Z,1349371444.572 [BuoyancyServo] Loaded
2012-10-04T17:24:04.572Z,1349371444.572 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-10-04T17:24:04.584Z,1349371444.584 [MassServo] Loaded
2012-10-04T17:24:04.585Z,1349371444.585 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-10-04T17:24:04.596Z,1349371444.596 [RudderServo] Loaded
2012-10-04T17:24:04.596Z,1349371444.596 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-10-04T17:24:04.597Z,1349371444.597 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-10-04T17:24:04.598Z,1349371444.598 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-10-04T17:24:04.614Z,1349371444.614 [DepthRateCalculator] Loaded
2012-10-04T17:24:04.614Z,1349371444.615 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-10-04T17:24:08.430Z,1349371448.430 [HFRadarModelCalc] Loaded
2012-10-04T17:24:08.430Z,1349371448.430 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2012-10-04T17:24:08.446Z,1349371448.446 [NavChart] Loaded
2012-10-04T17:24:08.446Z,1349371448.446 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-10-04T17:24:08.452Z,1349371448.452 [PitchRateCalculator] Loaded
2012-10-04T17:24:08.452Z,1349371448.452 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-10-04T17:24:08.458Z,1349371448.458 [SpeedCalculator] Loaded
2012-10-04T17:24:08.459Z,1349371448.459 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-10-04T17:24:08.473Z,1349371448.473 [TempGradientCalculator] Loaded
2012-10-04T17:24:08.473Z,1349371448.473 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-10-04T17:24:08.479Z,1349371448.479 [YawRateCalculator] Loaded
2012-10-04T17:24:08.479Z,1349371448.479 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-10-04T17:24:08.498Z,1349371448.498 [Navigation] Loaded
2012-10-04T17:24:08.498Z,1349371448.498 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-10-04T17:24:08.499Z,1349371448.499 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-10-04T17:24:08.500Z,1349371448.500 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-10-04T17:24:08.719Z,1349371448.718 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-10-04T17:24:08.719Z,1349371448.719 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-10-04T17:24:08.741Z,1349371448.741 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-10-04T17:24:08.742Z,1349371448.742 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-10-04T17:24:08.782Z,1349371448.782 [VerticalControl](DEBUG): Construct VerticalControl.
2012-10-04T17:24:08.825Z,1349371448.825 [VerticalControl] Loaded
2012-10-04T17:24:08.825Z,1349371448.825 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-10-04T17:24:08.826Z,1349371448.826 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-10-04T17:24:08.847Z,1349371448.847 [HorizontalControl] Loaded
2012-10-04T17:24:08.847Z,1349371448.847 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-10-04T17:24:08.848Z,1349371448.848 [SpeedControl](DEBUG): Construct SpeedControl.
2012-10-04T17:24:08.850Z,1349371448.850 [SpeedControl] Loaded
2012-10-04T17:24:08.850Z,1349371448.850 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-10-04T17:24:08.851Z,1349371448.851 [LoopControl](DEBUG): Construct LoopControl.
2012-10-04T17:24:08.851Z,1349371448.851 [LoopControl] Loaded
2012-10-04T17:24:08.852Z,1349371448.852 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-10-04T17:24:08.852Z,1349371448.852 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-10-04T17:24:08.853Z,1349371448.853 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-10-04T17:24:08.858Z,1349371448.858 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-10-04T17:24:08.863Z,1349371448.863 [AsyncPiEstimator] Loaded
2012-10-04T17:24:08.863Z,1349371448.863 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-10-04T17:24:08.864Z,1349371448.864 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406714E0
2012-10-04T17:24:08.865Z,1349371448.865 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-10-04T17:24:08.865Z,1349371448.865 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-10-04T17:24:08.986Z,1349371448.986 [AHRS_sp3003D] Loaded
2012-10-04T17:24:08.987Z,1349371448.987 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-10-04T17:24:08.000Z,1349371449.000 [Depth_Keller] Loaded
2012-10-04T17:24:09.000Z,1349371449.000 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-10-04T17:24:09.006Z,1349371449.006 [DropWeight] Loaded
2012-10-04T17:24:09.006Z,1349371449.006 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-10-04T17:24:09.117Z,1349371449.117 [DVL_micro] Loaded
2012-10-04T17:24:09.117Z,1349371449.118 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2012-10-04T17:24:09.119Z,1349371449.119 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406F14E0
2012-10-04T17:24:09.199Z,1349371449.199 [NAL9602] Loaded
2012-10-04T17:24:09.199Z,1349371449.199 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2012-10-04T17:24:09.249Z,1349371449.249 [Onboard] Loaded
2012-10-04T17:24:09.249Z,1349371449.249 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-10-04T17:24:09.256Z,1349371449.256 [Radio_Freewave] Loaded
2012-10-04T17:24:09.256Z,1349371449.256 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-10-04T17:24:09.257Z,1349371449.257 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-10-04T17:24:09.258Z,1349371449.258 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-10-04T17:24:09.326Z,1349371449.326 [CTD_NeilBrown] Loaded
2012-10-04T17:24:09.326Z,1349371449.326 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-10-04T17:24:09.328Z,1349371449.328 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407494E0
2012-10-04T17:24:09.345Z,1349371449.345 [Turbulence_NPS] Loaded
2012-10-04T17:24:09.345Z,1349371449.345 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread.
2012-10-04T17:24:09.346Z,1349371449.346 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 407794E0
2012-10-04T17:24:09.376Z,1349371449.376 [WetLabsBB2FL] Loaded
2012-10-04T17:24:09.376Z,1349371449.376 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2012-10-04T17:24:09.377Z,1349371449.377 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407A94E0
2012-10-04T17:24:09.378Z,1349371449.378 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-10-04T17:24:09.380Z,1349371449.380 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-10-04T17:24:09.381Z,1349371449.381 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-10-04T17:24:09.388Z,1349371449.388 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-10-04T17:24:09.389Z,1349371449.389 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407D94E0
2012-10-04T17:24:09.393Z,1349371449.393 [Supervisor](DEBUG): Running supervisor.
2012-10-04T17:24:09.394Z,1349371449.395 [CommandLine](INFO): Thread ID is 3045
2012-10-04T17:24:09.397Z,1349371449.397 [controlThread](INFO): Thread ID is 3044
2012-10-04T17:24:09.397Z,1349371449.397 [controlThread](DEBUG): Initializing ControlThread
2012-10-04T17:24:09.398Z,1349371449.398 [CycleStarter](INFO): Thread ID is 3043
2012-10-04T17:24:09.398Z,1349371449.398 [InternalSim](DEBUG):  InternalSim initializing...
2012-10-04T17:24:09.434Z,1349371449.434 [AsyncPiEstimator](INFO): Thread ID is 3106
2012-10-04T17:24:09.434Z,1349371449.434 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-10-04T17:24:09.443Z,1349371449.443 [SBIT](INFO): Initialize SBIT Component.
2012-10-04T17:24:09.444Z,1349371449.444 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9922
2012-10-04T17:24:09.444Z,1349371449.444 [IBIT](INFO): Initialize IBIT Component.
2012-10-04T17:24:09.445Z,1349371449.445 [CBIT](DEBUG): Initialize CBIT Component.
2012-10-04T17:24:09.445Z,1349371449.445 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2012-10-04T17:24:09.446Z,1349371449.446 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-10-04T17:24:09.447Z,1349371449.447 [DVL_micro](INFO): Thread ID is 3107
2012-10-04T17:24:09.456Z,1349371449.456 [DVL_micro](INFO): Initializing
2012-10-04T17:24:09.456Z,1349371449.456 [DVL_micro](INFO): start:Powering up
2012-10-04T17:24:09.457Z,1349371449.457 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-04T17:24:09.458Z,1349371449.458 [DVL_micro](INFO): Cycling power to configure device.
2012-10-04T17:24:09.471Z,1349371449.471 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-10-04T17:24:09.472Z,1349371449.472 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-10-04T17:24:09.472Z,1349371449.472 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-10-04T17:24:09.472Z,1349371449.473 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-10-04T17:24:09.473Z,1349371449.473 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-10-04T17:24:09.474Z,1349371449.474 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-10-04T17:24:09.475Z,1349371449.475 [Navigation](DEBUG): Initializing Navigation.
2012-10-04T17:24:09.475Z,1349371449.475 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-10-04T17:24:09.477Z,1349371449.477 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-10-04T17:24:09.478Z,1349371449.478 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-10-04T17:24:09.478Z,1349371449.478 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-10-04T17:24:09.484Z,1349371449.484 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-10-04T17:24:09.491Z,1349371449.491 [CTD_NeilBrown](INFO): Thread ID is 3108
2012-10-04T17:24:09.491Z,1349371449.491 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-10-04T17:24:09.499Z,1349371449.499 [Turbulence_NPS](INFO): Thread ID is 3109
2012-10-04T17:24:09.500Z,1349371449.500 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS.
2012-10-04T17:24:09.500Z,1349371449.500 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-10-04T17:24:09.507Z,1349371449.507 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-10-04T17:24:09.524Z,1349371449.524 [WetLabsBB2FL](INFO): Thread ID is 3110
2012-10-04T17:24:09.525Z,1349371449.525 [WetLabsBB2FL](INFO): Powering down
2012-10-04T17:24:09.544Z,1349371449.544 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-04T17:24:09.551Z,1349371449.551 [NavChartDb](INFO): Thread ID is 3111
2012-10-04T17:24:09.553Z,1349371449.553 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-10-04T17:24:09.563Z,1349371449.563 [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>


2012-10-04T17:24:09.563Z,1349371449.563 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-10-04T17:24:09.571Z,1349371449.571 [Turbulence_NPS](INFO): Pause powering down
2012-10-04T17:24:09.599Z,1349371449.599 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-10-04T17:24:09.599Z,1349371449.599 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-10-04T17:24:09.599Z,1349371449.599 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-10-04T17:24:09.599Z,1349371449.599 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-10-04T17:24:09.617Z,1349371449.617 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-10-04T17:24:09.619Z,1349371449.619 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-10-04T17:24:09.622Z,1349371449.622 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-04T17:24:09.631Z,1349371449.631 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-10-04T17:24:09.634Z,1349371449.634 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-04T17:24:09.641Z,1349371449.641 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-10-04T17:24:09.650Z,1349371449.650 [Default:D.SetSpeed](DEBUG): Construct.
2012-10-04T17:24:09.654Z,1349371449.654 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-04T17:24:09.659Z,1349371449.659 [Default:F.Wait](DEBUG): Construct Wait.
2012-10-04T17:24:09.662Z,1349371449.662 [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>


2012-10-04T17:24:09.667Z,1349371449.667 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,MassServo,RudderServo,SBIT,IBIT,CBIT,Reporter,logger,
2012-10-04T17:24:09.687Z,1349371449.687 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-10-04T17:24:09.818Z,1349371449.818 [Radio_Freewave](INFO): Powering up
2012-10-04T17:24:09.902Z,1349371449.902 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-10-04T17:24:09.907Z,1349371449.907 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-10-04T17:24:09.913Z,1349371449.913 [MassServo](DEBUG): Initializing EZServoServo.
2012-10-04T17:24:09.915Z,1349371449.915 [MassServo](DEBUG): Initializing MassServo.
2012-10-04T17:24:09.933Z,1349371449.933 [RudderServo](DEBUG): Initializing EZServoServo.
2012-10-04T17:24:09.946Z,1349371449.946 [RudderServo](DEBUG): Initializing RudderServo.
2012-10-04T17:24:11.779Z,1349371451.779 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-04T17:24:11.779Z,1349371451.779 [DVL_micro](INFO): Querying output modes
2012-10-04T17:24:11.779Z,1349371451.779 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-10-04T17:24:11.783Z,1349371451.783 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-10-04T17:24:11.783Z,1349371451.783 [DVL_micro](INFO): NQ1 output enabled
2012-10-04T17:24:11.783Z,1349371451.783 [DVL_micro](INFO): RSSI output enabled
2012-10-04T17:24:11.783Z,1349371451.783 [DVL_micro](INFO): ADCP output enabled
2012-10-04T17:24:11.783Z,1349371451.783 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-10-04T17:24:11.795Z,1349371451.795 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2012-10-04T17:24:11.800Z,1349371451.800 [DVL_micro](INFO): pause:Powering down
2012-10-04T17:24:15.073Z,1349371455.073 [NAL9602](INFO): Powering up NAL9602
2012-10-04T17:24:16.071Z,1349371456.071 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.823200 degree
2012-10-04T17:24:16.072Z,1349371456.072 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2012-10-04T17:24:16.073Z,1349371456.073 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121827.000000 degree
2012-10-04T17:24:16.075Z,1349371456.075 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2012-10-04T17:24:16.075Z,1349371456.075 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2012-10-04T17:24:16.076Z,1349371456.076 [CommandLine](IMPORTANT): got command report touch Turbulence_NPS.packetNum
2012-10-04T17:24:16.561Z,1349371456.561 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Depth_Keller,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,MassServo,RudderServo,SBIT,IBIT,CBIT,Reporter,logger,
2012-10-04T17:24:25.350Z,1349371465.351 [SBIT](IMPORTANT): Beginning Startup BIT
2012-10-04T17:24:25.353Z,1349371465.353 [CBIT](IMPORTANT): Beginning GF scan
2012-10-04T17:24:27.143Z,1349371467.143 [NAL9602](INFO): NAL9602 initialized
2012-10-04T17:24:35.711Z,1349371475.711 [NAL9602](INFO): Powering down
2012-10-04T17:24:53.578Z,1349371493.579 [CBIT](IMPORTANT): No ground fault detected
2012-10-04T17:25:20.944Z,1349371520.944 [SBIT](IMPORTANT): SBIT PASSED
2012-10-04T17:25:21.331Z,1349371521.331 [MissionManager](IMPORTANT): Started mission Startup
2012-10-04T17:25:21.331Z,1349371521.331 [Startup] Running Loop=1
2012-10-04T17:25:21.331Z,1349371521.331 [Startup](INFO): Aggregate::initialize Startup
2012-10-04T17:25:21.331Z,1349371521.331 [Startup:A.GoToSurface] Running Loop=1
2012-10-04T17:25:21.331Z,1349371521.331 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-04T17:25:21.337Z,1349371521.337 [Startup:StartupSatComms] Running Loop=1
2012-10-04T17:25:21.337Z,1349371521.337 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-10-04T17:25:21.338Z,1349371521.338 [Startup:StartupSatComms:A] Running Loop=1
2012-10-04T17:25:21.731Z,1349371521.731 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-04T17:25:21.733Z,1349371521.733 [Startup:StartupSatComms:A] Stopped
2012-10-04T17:25:21.733Z,1349371521.733 [Startup:StartupSatComms:B] Running Loop=1
2012-10-04T17:25:22.131Z,1349371522.131 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-10-04T17:25:22.518Z,1349371522.518 [NAL9602](INFO): Powering up
2012-10-04T17:25:33.347Z,1349371533.347 [NAL9602](INFO): NAL9602 initialized
2012-10-04T17:25:35.234Z,1349371535.234 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:25:39.538Z,1349371539.538 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:25:41.854Z,1349371541.854 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:25:46.170Z,1349371546.170 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:25:53.682Z,1349371553.682 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:03.994Z,1349371563.994 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:08.314Z,1349371568.314 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:12.155Z,1349371572.155 [CommandLine](IMPORTANT): got command run 
2012-10-04T17:26:12.155Z,1349371572.155 [CommandLine](FAULT): Incomplete syntax. Try: help run
2012-10-04T17:26:12.226Z,1349371572.226 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:19.511Z,1349371579.511 [CommandLine](IMPORTANT): got command run 
2012-10-04T17:26:19.511Z,1349371579.511 [CommandLine](FAULT): Incomplete syntax. Try: help run
2012-10-04T17:26:19.747Z,1349371579.747 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:21.759Z,1349371581.759 [Startup:StartupSatComms:B](INFO): Timed out from 2012-10-04T17:25:21.7Z
2012-10-04T17:26:21.760Z,1349371581.760 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2012-10-04T17:26:21.760Z,1349371581.760 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2012-10-04T17:26:21.760Z,1349371581.760 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2012-10-04T17:26:21.760Z,1349371581.760 [Startup:StartupSatComms:B] Stopped
2012-10-04T17:26:21.760Z,1349371581.760 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-10-04T17:26:21.760Z,1349371581.760 [Startup:StartupSatComms] Stopped
2012-10-04T17:26:21.760Z,1349371581.760 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-10-04T17:26:21.761Z,1349371581.761 [Startup](INFO): Completed Startup
2012-10-04T17:26:21.761Z,1349371581.761 [Startup] Stopped
2012-10-04T17:26:21.762Z,1349371581.761 [Startup](INFO): Aggregate::uninitialize Startup
2012-10-04T17:26:21.762Z,1349371581.761 [Startup:A.GoToSurface] Stopped
2012-10-04T17:26:21.762Z,1349371581.762 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-04T17:26:22.159Z,1349371582.159 [MissionManager](IMPORTANT): Started mission Default
2012-10-04T17:26:22.159Z,1349371582.159 [Default] Running Loop=1
2012-10-04T17:26:22.159Z,1349371582.159 [Default](INFO): Aggregate::initialize Default
2012-10-04T17:26:22.159Z,1349371582.159 [Default:D.SetSpeed] Running Loop=1
2012-10-04T17:26:22.159Z,1349371582.159 [Default:D.SetSpeed](DEBUG): Initialize.
2012-10-04T17:26:22.160Z,1349371582.160 [Default:E.GoToSurface] Running Loop=1
2012-10-04T17:26:22.160Z,1349371582.160 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-04T17:26:22.160Z,1349371582.160 [Default:Iridium] Running Loop=1
2012-10-04T17:26:22.160Z,1349371582.160 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-10-04T17:26:22.160Z,1349371582.160 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-04T17:26:22.160Z,1349371582.160 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-10-04T17:26:22.160Z,1349371582.160 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-10-04T17:26:22.161Z,1349371582.161 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-04T17:26:22.161Z,1349371582.161 [Default:E.GoToSurface] Running Loop=1
2012-10-04T17:26:22.167Z,1349371582.167 [Default:D.SetSpeed] Running Loop=1
2012-10-04T17:26:22.177Z,1349371582.177 [Default:Iridium:B.GoToSurface] Stopped
2012-10-04T17:26:22.177Z,1349371582.177 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-04T17:26:22.177Z,1349371582.177 [Default:Iridium:Read_Iridium] Running Loop=1
2012-10-04T17:26:22.177Z,1349371582.177 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-04T17:26:22.182Z,1349371582.182 [Default:GPS] Running Loop=1
2012-10-04T17:26:22.183Z,1349371582.183 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-10-04T17:26:22.183Z,1349371582.183 [Default:GPS:A.SetSpeed] Running Loop=1
2012-10-04T17:26:22.183Z,1349371582.183 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-10-04T17:26:22.183Z,1349371582.183 [Default:GPS:B.GoToSurface] Running Loop=1
2012-10-04T17:26:22.183Z,1349371582.183 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-04T17:26:22.188Z,1349371582.188 [Default:GPS:B.GoToSurface] Stopped
2012-10-04T17:26:22.189Z,1349371582.188 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-04T17:26:22.189Z,1349371582.189 [Default:GPS:Read_GPS] Running Loop=1
2012-10-04T17:26:22.189Z,1349371582.189 [Default:GPS:A.SetSpeed] Running Loop=1
2012-10-04T17:26:22.566Z,1349371582.566 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-10-04T17:26:22.569Z,1349371582.569 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-04T17:26:22.571Z,1349371582.571 [Default:GPS:Read_GPS] Stopped
2012-10-04T17:26:22.571Z,1349371582.571 [Default:GPS:D] Running Loop=1
2012-10-04T17:26:22.962Z,1349371582.962 [Default:GPS:D] Stopped
2012-10-04T17:26:22.963Z,1349371582.963 [Default:GPS](INFO): Completed Default:GPS
2012-10-04T17:26:22.963Z,1349371582.963 [Default:GPS] Stopped
2012-10-04T17:26:22.963Z,1349371582.963 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-10-04T17:26:22.963Z,1349371582.963 [Default:GPS:A.SetSpeed] Stopped
2012-10-04T17:26:22.963Z,1349371582.963 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-10-04T17:26:28.466Z,1349371588.466 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:31.447Z,1349371591.447 [CommandLine](IMPORTANT): got command run ./Missions/Science/science_to_67_70.xml
2012-10-04T17:26:31.447Z,1349371591.447 [MissionManager](INFO): Loading Mission: ./Missions/Science/science_to_67_70.xml
2012-10-04T17:26:31.527Z,1349371591.527 [MissionManager](INFO): DefineArg science_to_67_70.MinAltitude = 10.000000 m
2012-10-04T17:26:31.531Z,1349371591.531 [MissionManager](INFO): DefineArg science_to_67_70.MaxDepth = 105.000000 m
2012-10-04T17:26:31.533Z,1349371591.533 [MissionManager](INFO): DefineArg science_to_67_70.MinOffshore = 2000.000000 m
2012-10-04T17:26:31.536Z,1349371591.536 [MissionManager](INFO): DefineArg science_to_67_70.YoYoMinDepth = 3.000000 m
2012-10-04T17:26:31.540Z,1349371591.540 [MissionManager](INFO): DefineArg science_to_67_70.YoYoMaxDepth = 100.000000 m
2012-10-04T17:26:31.543Z,1349371591.543 [MissionManager](INFO): DefineArg science_to_67_70.YoYoUpPitch = 20.000000 arcdeg
2012-10-04T17:26:31.546Z,1349371591.546 [MissionManager](INFO): DefineArg science_to_67_70.YoYoDownPitch = -15.000000 arcdeg
2012-10-04T17:26:31.550Z,1349371591.550 [MissionManager](INFO): DefineArg science_to_67_70.WptLat = 36.120000 arcdeg
2012-10-04T17:26:31.553Z,1349371591.553 [MissionManager](INFO): DefineArg science_to_67_70.WptLon = -123.486000 arcdeg
2012-10-04T17:26:31.556Z,1349371591.556 [MissionManager](INFO): DefineArg science_to_67_70.NeedCommsTime = 120.000000 min
2012-10-04T17:26:31.559Z,1349371591.559 [MissionManager](INFO): DefineArg science_to_67_70.Speed = 1.000000 m/s
2012-10-04T17:26:31.562Z,1349371591.562 [MissionManager](INFO): DefineArg science_to_67_70.Timeout = 36.000000 h
2012-10-04T17:26:31.566Z,1349371591.566 [MissionManager](INFO): DefineArg science_to_67_70.BuoyancyNeutral = 0.000330 n/a
2012-10-04T17:26:31.569Z,1349371591.569 [science_to_67_70:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2012-10-04T17:26:31.577Z,1349371591.577 [science_to_67_70:AltEnvWrapper:B.Wait](DEBUG): Construct Wait.
2012-10-04T17:26:31.578Z,1349371591.578 [science_to_67_70:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2012-10-04T17:26:31.590Z,1349371591.589 [science_to_67_70:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2012-10-04T17:26:31.596Z,1349371591.596 [science_to_67_70:OffshoreWrapper:B.Wait](DEBUG): Construct Wait.
2012-10-04T17:26:31.597Z,1349371591.597 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml
2012-10-04T17:26:31.615Z,1349371591.615 [MissionManager](INFO): DefineArg science_to_67_70:SURFACECOMMS.SurfaceDepthRate = nan m/s
2012-10-04T17:26:31.618Z,1349371591.618 [MissionManager](INFO): DefineArg science_to_67_70:SURFACECOMMS.SurfacePitch = nan arcdeg
2012-10-04T17:26:31.623Z,1349371591.623 [MissionManager](INFO): DefineArg science_to_67_70:SURFACECOMMS.SurfaceSpeed = 0.500000 m/s
2012-10-04T17:26:31.625Z,1349371591.625 [MissionManager](INFO): DefineArg science_to_67_70:SURFACECOMMS.IridiumTimeout = 30.000000 min
2012-10-04T17:26:31.627Z,1349371591.627 [science_to_67_70:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-04T17:26:31.637Z,1349371591.638 [MissionManager](INFO): RedefineArg science_to_67_70:SURFACECOMMS.SurfacePitch = 20.000000 arcdeg
2012-10-04T17:26:31.643Z,1349371591.643 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2012-10-04T17:26:31.734Z,1349371591.734 [MissionManager](INFO): DefineArg science_to_67_70:Science.SampleISUS = 0 bool
2012-10-04T17:26:31.741Z,1349371591.741 [MissionManager](INFO): DefineArg science_to_67_70:Science.SampleRSSI = 1 bool
2012-10-04T17:26:31.747Z,1349371591.747 [MissionManager](INFO): DefineArg science_to_67_70:Science.SampleADCP = 1 bool
2012-10-04T17:26:31.750Z,1349371591.750 [MissionManager](INFO): DefineArg science_to_67_70:Science.PeakDetectChlActive = 0 bool
2012-10-04T17:26:31.757Z,1349371591.757 [MissionManager](INFO): DefineArg science_to_67_70:Science.PeakDetectNO3Active = 0 bool
2012-10-04T17:26:31.764Z,1349371591.764 [MissionManager](INFO): DefineArg science_to_67_70:Science.SampleAanderaaO2 = 0.000000 n/a
2012-10-04T17:26:31.779Z,1349371591.779 [MissionManager](INFO): DefineArg science_to_67_70:Science.SampleNeilBrown = 1.000000 n/a
2012-10-04T17:26:31.782Z,1349371591.782 [MissionManager](INFO): DefineArg science_to_67_70:Science.SampleTurbulence_NPS = 1.000000 n/a
2012-10-04T17:26:31.789Z,1349371591.789 [MissionManager](INFO): DefineArg science_to_67_70:Science.SampleWetLabsBB2FL = 1.000000 n/a
2012-10-04T17:26:31.797Z,1349371591.797 [MissionManager](INFO): DefineArg science_to_67_70:Science.EnabledDVL = 1.000000 n/a
2012-10-04T17:26:31.801Z,1349371591.801 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakChl = 0.000000 ug/l
2012-10-04T17:26:31.813Z,1349371591.813 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakChlDepth = 0.000000 m
2012-10-04T17:26:31.820Z,1349371591.820 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakChlLatitude = nan arcdeg
2012-10-04T17:26:31.827Z,1349371591.827 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakChlLongitude = nan arcdeg
2012-10-04T17:26:31.835Z,1349371591.835 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakNO3 = 0.000000 umol/l
2012-10-04T17:26:31.838Z,1349371591.838 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakNO3Depth = 0.000000 m
2012-10-04T17:26:31.845Z,1349371591.845 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakNO3Latitude = nan arcdeg
2012-10-04T17:26:31.852Z,1349371591.852 [MissionManager](INFO): DefineOutput science_to_67_70:Science.PeakNO3Longitude = nan arcdeg
2012-10-04T17:26:31.877Z,1349371591.877 [science_to_67_70:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2012-10-04T17:26:31.902Z,1349371591.902 [science_to_67_70:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2012-10-04T17:26:31.917Z,1349371591.917 [MissionManager](INFO): RedefineArg science_to_67_70:Science.SampleISUS = 1 bool
2012-10-04T17:26:31.919Z,1349371591.919 [MissionManager](INFO): RedefineArg science_to_67_70:Science.PeakDetectChlActive = 1 bool
2012-10-04T17:26:31.920Z,1349371591.920 [science_to_67_70:G.Buoyancy](DEBUG): Construct Buoyancy.
2012-10-04T17:26:31.924Z,1349371591.924 [science_to_67_70:H.SetSpeed](DEBUG): Construct.
2012-10-04T17:26:31.938Z,1349371591.938 [science_to_67_70:I.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2012-10-04T17:26:31.948Z,1349371591.948 [science_to_67_70:J.YoYo](DEBUG): Construct YoYo.
2012-10-04T17:26:31.968Z,1349371591.968 [science_to_67_70:Wpt.Point](DEBUG): Construct.
2012-10-04T17:26:32.007Z,1349371592.007 [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/Trigger http://aosn.mbari.org/tethys/Xml/Trigger.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="science_to_67_70">

    <Description>
        Vehicle yo-yo's to the specified waypoint, with science turned on.
    </Description>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>10.0</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>105.0</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:meter/><Value>2000.0</Value></DefineArg>

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>3.0</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>100.0</Value></DefineArg>

    <DefineArg Name="YoYoUpPitch"><Description>
        Vehicle up pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>20.0</Value></DefineArg>

    <DefineArg Name="YoYoDownPitch"><Description>
        Vehicle down pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>-15.0</Value></DefineArg>

    <DefineArg Name="WptLat"><Description>
        Latitude of waypoint.
    </Description><Units:degree/><Value>36.120</Value></DefineArg>

    <DefineArg Name="WptLon"><Description>
        Longitude of waypoint.
    </Description><Units:degree/><Value>-123.486</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        Elapsed time after previous surface communications when vehicle will
        begin to ascend for additional surface communications, if the vehicle
        has a positive pitch. If the vehicle has a negative pitch, it will wait
        up to 10 minutes more to begin ascent.
    </Description><Units:minute/><Value>120</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="Timeout"><Description>
        Maximum length of mission
    </Description><Units:hour/><Value>36</Value></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position while performing the YoYo behavior. Defaults
        to buoyancyNeutral setting in the Config/Control.cfg file.
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

    <Timeout Duration="Timeout"/>

    <Aggregate Id="AltEnvWrapper">

        <When><Arg Name="MinAltitude"/>
            <Gt><Units:meter/><Value>0</Value></Gt>
        </When>

        <Guidance:AltitudeEnvelope RunIn="Parallel">
            <Description>
                Safety behavior that keeps vehicle off sea floor
            </Description>
            <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="MinAltitude"/></Setting>
        </Guidance:AltitudeEnvelope>

        <Guidance:Wait RunIn="Sequence"/>

    </Aggregate>

    <Guidance:DepthEnvelope RunIn="Parallel">
        <Description>
            Safety behavior that keeps vehicle from going too deep
        </Description>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="MaxDepth"/></Setting>
    </Guidance:DepthEnvelope>

    <Aggregate Id="OffshoreWrapper">

        <When><Arg Name="MinOffshore"/>
            <Gt><Units:meter/><Value>0</Value></Gt>
        </When>

        <Guidance:OffshoreEnvelope RunIn="Parallel">
            <Description>
                Safety behavior that keeps vehicle away from the shore
            </Description>
            <Setting><Guidance:OffshoreEnvelope.minOffshore/><Arg Name="MinOffshore"/></Setting>
        </Guidance:OffshoreEnvelope>

        <Guidance:Wait RunIn="Sequence"/>

    </Aggregate>

    <Insert Filename="Insert/Surface.xml" Id="SURFACECOMMS">
        <RedefineArg Name="SurfacePitch"><Units:degree/><Value>20</Value></RedefineArg>
    </Insert>

<!-- GPS Update.  Don't go too long w/o a GPS fix. -->

    <Aggregate Id="NeedComms">

        <When><Universal:platform_pitch_angle/>
            <Gt><Units:degree/><Value>0</Value></Gt>
            <And>
            <Elapsed><Universal:latitude_fix/></Elapsed><Gt><Arg Name="NeedCommsTime"/></Gt></And>
            <Or>
            <Elapsed><Universal:latitude_fix/></Elapsed><Gt><Arg Name="NeedCommsTime"/><Add><Units:minute/><Value>10</Value></Add></Gt></Or>
        </When>

        <Call RefId="SURFACECOMMS"/>

    </Aggregate>

    <Insert Filename="Insert/Science.xml">
        <Description>
            If we're executing here or below, lets' get science data!
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

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

    <Guidance:SetSpeed RunIn="Parallel">
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope RunIn="Parallel">
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
        <Setting><Guidance:DepthEnvelope.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:YoYo RunIn="Parallel">
        <Setting><Guidance:YoYo.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
        <Setting><Guidance:YoYo.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
    </Guidance:YoYo>

    <Guidance:Point Id="Wpt" RunIn="Sequence">
        <Setting><Guidance:Point.latitude/><Arg Name="WptLat"/></Setting>
        <Setting><Guidance:Point.longitude/><Arg Name="WptLon"/></Setting>
    </Guidance:Point>

</Mission>


2012-10-04T17:26:32.007Z,1349371592.007 [CommandLine](IMPORTANT): Running ./Missions/Science/science_to_67_70.xml
2012-10-04T17:26:32.867Z,1349371592.867 [Default] Stopped
2012-10-04T17:26:32.867Z,1349371592.867 [Default](INFO): Aggregate::uninitialize Default
2012-10-04T17:26:32.867Z,1349371592.867 [Default:Iridium] Stopped
2012-10-04T17:26:32.868Z,1349371592.868 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-10-04T17:26:32.868Z,1349371592.868 [Default:Iridium:A.SetSpeed] Stopped
2012-10-04T17:26:32.868Z,1349371592.868 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-10-04T17:26:32.868Z,1349371592.868 [Default:Iridium:Read_Iridium] Stopped
2012-10-04T17:26:32.868Z,1349371592.868 [Default:D.SetSpeed] Stopped
2012-10-04T17:26:32.868Z,1349371592.868 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-10-04T17:26:32.868Z,1349371592.868 [Default:E.GoToSurface] Stopped
2012-10-04T17:26:32.868Z,1349371592.868 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-04T17:26:32.868Z,1349371592.868 [MissionManager](IMPORTANT): Started mission science_to_67_70
2012-10-04T17:26:32.868Z,1349371592.868 [science_to_67_70] Running Loop=1
2012-10-04T17:26:32.868Z,1349371592.868 [science_to_67_70](INFO): Aggregate::initialize science_to_67_70
2012-10-04T17:26:32.868Z,1349371592.868 [science_to_67_70:B.DepthEnvelope] Running Loop=1
2012-10-04T17:26:32.869Z,1349371592.869 [science_to_67_70:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science](INFO): Aggregate::initialize science_to_67_70:Science
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science:A] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science:B] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science:C] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science:D] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science:E] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science:F] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:Science:G] Running Loop=1
2012-10-04T17:26:32.870Z,1349371592.870 [science_to_67_70:G.Buoyancy] Running Loop=1
2012-10-04T17:26:32.871Z,1349371592.871 [science_to_67_70:G.Buoyancy](DEBUG): Initialize Buoyancy Component.
2012-10-04T17:26:32.871Z,1349371592.871 [science_to_67_70:H.SetSpeed] Running Loop=1
2012-10-04T17:26:32.871Z,1349371592.871 [science_to_67_70:H.SetSpeed](DEBUG): Initialize.
2012-10-04T17:26:32.871Z,1349371592.871 [science_to_67_70:I.DepthEnvelope] Running Loop=1
2012-10-04T17:26:32.871Z,1349371592.871 [science_to_67_70:I.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2012-10-04T17:26:32.872Z,1349371592.872 [science_to_67_70:J.YoYo] Running Loop=1
2012-10-04T17:26:32.872Z,1349371592.872 [science_to_67_70:J.YoYo](DEBUG): Initialize YoYoComponent.
2012-10-04T17:26:32.872Z,1349371592.872 [science_to_67_70:SURFACECOMMS] Running Loop=1
2012-10-04T17:26:32.872Z,1349371592.872 [science_to_67_70:SURFACECOMMS](INFO): Aggregate::initialize science_to_67_70:SURFACECOMMS
2012-10-04T17:26:32.872Z,1349371592.872 [science_to_67_70:SURFACECOMMS:A.GoToSurface] Running Loop=1
2012-10-04T17:26:32.873Z,1349371592.872 [science_to_67_70:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-04T17:26:32.873Z,1349371592.874 [science_to_67_70:J.YoYo] Running Loop=1
2012-10-04T17:26:32.878Z,1349371592.878 [science_to_67_70:I.DepthEnvelope] Running Loop=1
2012-10-04T17:26:32.884Z,1349371592.884 [science_to_67_70:H.SetSpeed] Running Loop=1
2012-10-04T17:26:32.888Z,1349371592.888 [science_to_67_70:G.Buoyancy] Running Loop=1
2012-10-04T17:26:32.893Z,1349371592.893 [science_to_67_70:Science] Running Loop=1
2012-10-04T17:26:32.893Z,1349371592.893 [science_to_67_70:Science:PeakDetectChl] Running Loop=1
2012-10-04T17:26:32.893Z,1349371592.894 [science_to_67_70:Science:PeakDetectChl](INFO): Aggregate::initialize science_to_67_70:Science:PeakDetectChl
2012-10-04T17:26:32.894Z,1349371592.894 [science_to_67_70:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2012-10-04T17:26:32.894Z,1349371592.894 [science_to_67_70:Science:PeakDetectChl:A.PeakDetectVsDepth](INFO): Initialize.
2012-10-04T17:26:32.900Z,1349371592.900 [science_to_67_70:Science:G] Running Loop=1
2012-10-04T17:26:32.900Z,1349371592.900 [science_to_67_70:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2012-10-04T17:26:32.901Z,1349371592.901 [science_to_67_70:Science:F] Running Loop=1
2012-10-04T17:26:32.902Z,1349371592.902 [science_to_67_70:Science:F](DEBUG): Initialize ReadDataComponent to sense DVL_micro.Beam1RSSI
2012-10-04T17:26:32.904Z,1349371592.904 [science_to_67_70:Science:E] Running Loop=1
2012-10-04T17:26:32.904Z,1349371592.904 [science_to_67_70:Science:E](DEBUG): Initialize ReadDataComponent to sense DVL_micro.AdcpXWaterVelocity
2012-10-04T17:26:32.905Z,1349371592.905 [science_to_67_70:Science:D] Running Loop=1
2012-10-04T17:26:32.906Z,1349371592.906 [science_to_67_70:Science:D](DEBUG): Initialize ReadDataComponent to sense Turbulence_NPS.MicroCond
2012-10-04T17:26:32.908Z,1349371592.908 [science_to_67_70:Science:C] Running Loop=1
2012-10-04T17:26:32.908Z,1349371592.908 [science_to_67_70:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2012-10-04T17:26:32.909Z,1349371592.909 [science_to_67_70:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2012-10-04T17:26:32.910Z,1349371592.910 [science_to_67_70:Science:B] Running Loop=1
2012-10-04T17:26:32.911Z,1349371592.911 [science_to_67_70:Science:B](DEBUG): Initialize ReadDataComponent to sense mole_concentration_of_nitrate_in_sea_water
2012-10-04T17:26:32.917Z,1349371592.917 [science_to_67_70:SURFACECOMMS:B] Running Loop=1
2012-10-04T17:26:32.918Z,1349371592.918 [science_to_67_70:SURFACECOMMS:B](INFO): Aggregate::initialize science_to_67_70:SURFACECOMMS:B
2012-10-04T17:26:32.918Z,1349371592.918 [science_to_67_70:SURFACECOMMS:B:A] Running Loop=1
2012-10-04T17:26:32.918Z,1349371592.918 [science_to_67_70:OffshoreWrapper] Running Loop=1
2012-10-04T17:26:32.918Z,1349371592.918 [science_to_67_70:OffshoreWrapper](INFO): Aggregate::initialize science_to_67_70:OffshoreWrapper
2012-10-04T17:26:32.918Z,1349371592.918 [science_to_67_70:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1
2012-10-04T17:26:32.919Z,1349371592.919 [science_to_67_70:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2012-10-04T17:26:32.919Z,1349371592.919 [science_to_67_70:OffshoreWrapper:B.Wait] Running Loop=1
2012-10-04T17:26:32.919Z,1349371592.919 [science_to_67_70:OffshoreWrapper:B.Wait](DEBUG): Initialize Wait Component.
2012-10-04T17:26:32.924Z,1349371592.924 [science_to_67_70:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1
2012-10-04T17:26:32.929Z,1349371592.929 [science_to_67_70:B.DepthEnvelope] Running Loop=1
2012-10-04T17:26:32.931Z,1349371592.931 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4
2012-10-04T17:26:32.931Z,1349371592.931 [WetLabsBB2FL](INFO): Powering up
2012-10-04T17:26:32.936Z,1349371592.936 [science_to_67_70:AltEnvWrapper] Running Loop=1
2012-10-04T17:26:32.936Z,1349371592.936 [science_to_67_70:AltEnvWrapper](INFO): Aggregate::initialize science_to_67_70:AltEnvWrapper
2012-10-04T17:26:32.936Z,1349371592.936 [science_to_67_70:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1
2012-10-04T17:26:32.936Z,1349371592.936 [science_to_67_70:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2012-10-04T17:26:32.937Z,1349371592.937 [science_to_67_70:AltEnvWrapper:B.Wait] Running Loop=1
2012-10-04T17:26:32.937Z,1349371592.937 [science_to_67_70:AltEnvWrapper:B.Wait](DEBUG): Initialize Wait Component.
2012-10-04T17:26:32.942Z,1349371592.941 [science_to_67_70:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1
2012-10-04T17:26:32.955Z,1349371592.955 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-10-04T17:26:33.075Z,1349371593.075 [Turbulence_NPS](INFO): Resume powering up
2012-10-04T17:26:33.076Z,1349371593.076 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-10-04T17:26:33.123Z,1349371593.124 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-04T17:26:33.124Z,1349371593.124 [DVL_micro](INFO): resume:Powering up
2012-10-04T17:26:33.124Z,1349371593.124 [DVL_micro](INFO): Cycling power to configure device.
2012-10-04T17:26:33.338Z,1349371593.338 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:33.353Z,1349371593.353 [science_to_67_70:J.YoYo] Preempted
2012-10-04T17:26:33.353Z,1349371593.353 [science_to_67_70:I.DepthEnvelope] Preempted
2012-10-04T17:26:33.354Z,1349371593.353 [science_to_67_70:H.SetSpeed] Preempted
2012-10-04T17:26:33.354Z,1349371593.353 [science_to_67_70:G.Buoyancy] Preempted
2012-10-04T17:26:33.354Z,1349371593.354 [science_to_67_70:Science] Preempted
2012-10-04T17:26:33.354Z,1349371593.354 [science_to_67_70:Science:B] Preempted
2012-10-04T17:26:33.354Z,1349371593.354 [science_to_67_70:Science:C] Preempted
2012-10-04T17:26:33.354Z,1349371593.354 [science_to_67_70:Science:D] Preempted
2012-10-04T17:26:33.354Z,1349371593.354 [science_to_67_70:Science:E] Preempted
2012-10-04T17:26:33.354Z,1349371593.354 [science_to_67_70:Science:F] Preempted
2012-10-04T17:26:33.354Z,1349371593.354 [science_to_67_70:Science:G] Preempted
2012-10-04T17:26:33.355Z,1349371593.355 [science_to_67_70:SURFACECOMMS:B:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-04T17:26:33.357Z,1349371593.357 [science_to_67_70:SURFACECOMMS:B:A] Stopped
2012-10-04T17:26:33.357Z,1349371593.357 [science_to_67_70:SURFACECOMMS:B:B] Running Loop=1
2012-10-04T17:26:33.443Z,1349371593.443 [Turbulence_NPS](INFO): Pause powering down
2012-10-04T17:26:33.749Z,1349371593.749 [science_to_67_70:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-10-04T17:26:34.123Z,1349371594.122 [WetLabsBB2FL](INFO): Powering down
2012-10-04T17:26:34.549Z,1349371594.549 [science_to_67_70:AltEnvWrapper:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2012-10-04T17:26:35.131Z,1349371595.131 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-04T17:26:35.131Z,1349371595.131 [DVL_micro](INFO): Querying output modes
2012-10-04T17:26:35.131Z,1349371595.131 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-10-04T17:26:35.139Z,1349371595.138 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-10-04T17:26:35.139Z,1349371595.139 [DVL_micro](INFO): NQ1 output enabled
2012-10-04T17:26:35.139Z,1349371595.139 [DVL_micro](INFO): RSSI output enabled
2012-10-04T17:26:35.139Z,1349371595.139 [DVL_micro](INFO): ADCP output enabled
2012-10-04T17:26:35.139Z,1349371595.139 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-10-04T17:26:35.147Z,1349371595.147 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2012-10-04T17:26:35.148Z,1349371595.148 [DVL_micro](INFO): RSSI unrequested
2012-10-04T17:26:35.148Z,1349371595.148 [DVL_micro](INFO): ADCP unrequested
2012-10-04T17:26:35.149Z,1349371595.149 [DVL_micro](INFO): Cycling power to configure device.
2012-10-04T17:26:37.155Z,1349371597.155 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-04T17:26:37.155Z,1349371597.155 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2012-10-04T17:26:37.163Z,1349371597.163 [DVL_micro](DEBUG): cmdResponse: q5S��I����fHLL�

2012-10-04T17:26:37.163Z,1349371597.163 [DVL_micro](INFO): Enabling NQ1 output
2012-10-04T17:26:37.163Z,1349371597.163 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2012-10-04T17:26:37.167Z,1349371597.167 [DVL_micro](DEBUG): cmdResponse: 
$#NQRSSI
2012-10-04T17:26:37.167Z,1349371597.167 [DVL_micro](INFO): Querying output modes
2012-10-04T17:26:37.167Z,1349371597.167 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-10-04T17:26:37.180Z,1349371597.180 [DVL_micro](DEBUG): cmdResponse: ����v�C����4�����g��^�@�M�z���������A�=�,����������������U��������������������������
2012-10-04T17:26:37.180Z,1349371597.180 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-10-04T17:26:37.187Z,1349371597.187 [DVL_micro](DEBUG): cmdResponse: �r���o�[�a�l�~��������y�O�,�(�1�,�=�V�3�
2012-10-04T17:26:37.807Z,1349371597.807 [DVL_micro](INFO): NQ1 requested
2012-10-04T17:26:37.807Z,1349371597.807 [DVL_micro](INFO): Cycling power to configure device.
2012-10-04T17:26:39.815Z,1349371599.815 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-04T17:26:39.815Z,1349371599.815 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2012-10-04T17:26:39.875Z,1349371599.875 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2012-10-04T17:26:39.987Z,1349371599.987 [DVL_micro](DEBUG): cmdResponse: 00
2012-10-04T17:26:39.987Z,1349371599.987 [DVL_micro](INFO): Enabling NQ1 output
2012-10-04T17:26:39.987Z,1349371599.987 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2012-10-04T17:26:40.149Z,1349371600.149 [science_to_67_70:SURFACECOMMS:B:B] Stopped
2012-10-04T17:26:40.150Z,1349371600.150 [science_to_67_70:SURFACECOMMS:B:C] Running Loop=1
2012-10-04T17:26:40.159Z,1349371600.159 [DVL_micro](DEBUG): cmdResponse: 01
2012-10-04T17:26:40.159Z,1349371600.159 [DVL_micro](INFO): Querying output modes
2012-10-04T17:26:40.159Z,1349371600.159 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-10-04T17:26:40.163Z,1349371600.163 [DVL_micro](DEBUG): cmdResponse: 01
2012-10-04T17:26:40.163Z,1349371600.163 [DVL_micro](INFO): NQ1 output enabled
2012-10-04T17:26:40.163Z,1349371600.163 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-10-04T17:26:40.167Z,1349371600.167 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2012-10-04T17:26:40.902Z,1349371600.902 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:41.050Z,1349371601.050 [science_to_67_70:SURFACECOMMS:B:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-04T17:26:41.052Z,1349371601.052 [science_to_67_70:SURFACECOMMS:B:C] Stopped
2012-10-04T17:26:41.052Z,1349371601.052 [science_to_67_70:SURFACECOMMS:B](INFO): Completed science_to_67_70:SURFACECOMMS:B
2012-10-04T17:26:41.052Z,1349371601.052 [science_to_67_70:SURFACECOMMS:B] Stopped
2012-10-04T17:26:41.052Z,1349371601.052 [science_to_67_70:SURFACECOMMS:B](INFO): Aggregate::uninitialize science_to_67_70:SURFACECOMMS:B
2012-10-04T17:26:41.053Z,1349371601.053 [science_to_67_70:SURFACECOMMS](INFO): Completed science_to_67_70:SURFACECOMMS
2012-10-04T17:26:41.053Z,1349371601.053 [science_to_67_70:SURFACECOMMS] Stopped
2012-10-04T17:26:41.053Z,1349371601.053 [science_to_67_70:SURFACECOMMS](INFO): Aggregate::uninitialize science_to_67_70:SURFACECOMMS
2012-10-04T17:26:41.053Z,1349371601.053 [science_to_67_70:SURFACECOMMS:A.GoToSurface] Stopped
2012-10-04T17:26:41.054Z,1349371601.053 [science_to_67_70:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-04T17:26:41.054Z,1349371601.054 [science_to_67_70:Wpt.Point] Running Loop=1
2012-10-04T17:26:41.054Z,1349371601.054 [science_to_67_70:Wpt.Point](DEBUG): Initialize.
2012-10-04T17:26:41.291Z,1349371601.291 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2012-10-04T17:26:41.311Z,1349371601.311 [science_to_67_70:J.YoYo] Running Loop=1
2012-10-04T17:26:41.312Z,1349371601.312 [science_to_67_70:I.DepthEnvelope] Running Loop=1
2012-10-04T17:26:41.312Z,1349371601.312 [science_to_67_70:H.SetSpeed] Running Loop=1
2012-10-04T17:26:41.313Z,1349371601.313 [science_to_67_70:G.Buoyancy] Running Loop=1
2012-10-04T17:26:41.313Z,1349371601.313 [science_to_67_70:Science] Running Loop=1
2012-10-04T17:26:41.314Z,1349371601.314 [science_to_67_70:Science:G] Running Loop=1
2012-10-04T17:26:41.314Z,1349371601.314 [science_to_67_70:Science:F] Running Loop=1
2012-10-04T17:26:41.315Z,1349371601.315 [science_to_67_70:Science:E] Running Loop=1
2012-10-04T17:26:41.315Z,1349371601.315 [science_to_67_70:Science:D] Running Loop=1
2012-10-04T17:26:41.315Z,1349371601.315 [science_to_67_70:Science:C] Running Loop=1
2012-10-04T17:26:41.315Z,1349371601.315 [science_to_67_70:Science:B] Running Loop=1
2012-10-04T17:26:41.395Z,1349371601.395 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:41.396Z,1349371601.397 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4
2012-10-04T17:26:41.397Z,1349371601.397 [WetLabsBB2FL](INFO): Powering up
2012-10-04T17:26:41.422Z,1349371601.422 [DVL_micro](INFO): RSSI requested
2012-10-04T17:26:41.422Z,1349371601.422 [DVL_micro](INFO): ADCP requested
2012-10-04T17:26:41.422Z,1349371601.422 [DVL_micro](INFO): Cycling power to configure device.
2012-10-04T17:26:41.523Z,1349371601.523 [Turbulence_NPS](INFO): Resume powering up
2012-10-04T17:26:41.523Z,1349371601.523 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-10-04T17:26:41.684Z,1349371601.684 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-10-04T17:26:43.431Z,1349371603.431 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-04T17:26:43.431Z,1349371603.431 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2012-10-04T17:26:43.603Z,1349371603.602 [DVL_micro](DEBUG): cmdResponse: 00
2012-10-04T17:26:43.603Z,1349371603.603 [DVL_micro](INFO): Enabling RSSI output
2012-10-04T17:26:43.603Z,1349371603.603 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7

2012-10-04T17:26:43.777Z,1349371603.777 [DVL_micro](DEBUG): cmdResponse: 16
2012-10-04T17:26:43.777Z,1349371603.777 [DVL_micro](INFO): Enabling ADCP output
2012-10-04T17:26:43.777Z,1349371603.777 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3

2012-10-04T17:26:43.939Z,1349371603.940 [DVL_micro](DEBUG): cmdResponse: 03 16
2012-10-04T17:26:43.940Z,1349371603.940 [DVL_micro](INFO): Enabling NQ1 output
2012-10-04T17:26:43.940Z,1349371603.940 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2012-10-04T17:26:44.111Z,1349371604.111 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-10-04T17:26:44.111Z,1349371604.111 [DVL_micro](INFO): Querying output modes
2012-10-04T17:26:44.112Z,1349371604.112 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2012-10-04T17:26:44.119Z,1349371604.119 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-10-04T17:26:44.119Z,1349371604.119 [DVL_micro](INFO): NQ1 output enabled
2012-10-04T17:26:44.120Z,1349371604.120 [DVL_micro](INFO): RSSI output enabled
2012-10-04T17:26:44.120Z,1349371604.120 [DVL_micro](INFO): ADCP output enabled
2012-10-04T17:26:44.120Z,1349371604.120 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2012-10-04T17:26:44.127Z,1349371604.128 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2012-10-04T17:26:44.153Z,1349371604.153 [CTD_NeilBrown](ERROR): Pressure reading out of range: -13.730000 decibar
2012-10-04T17:26:44.264Z,1349371604.264 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8
2012-10-04T17:26:44.319Z,1349371604.319 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28
2012-10-04T17:26:44.371Z,1349371604.371 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16
2012-10-04T17:26:44.427Z,1349371604.427 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2012-10-04T17:26:44.695Z,1349371604.695 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24
2012-10-04T17:26:44.799Z,1349371604.799 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28
2012-10-04T17:26:44.899Z,1349371604.899 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0
2012-10-04T17:26:45.003Z,1349371605.003 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2012-10-04T17:26:45.144Z,1349371605.144 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40
2012-10-04T17:26:45.199Z,1349371605.199 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60
2012-10-04T17:26:45.252Z,1349371605.252 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16
2012-10-04T17:26:45.303Z,1349371605.303 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2012-10-04T17:26:45.592Z,1349371605.592 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24
2012-10-04T17:26:45.695Z,1349371605.695 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29
2012-10-04T17:26:45.795Z,1349371605.795 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1
2012-10-04T17:26:45.899Z,1349371605.899 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2012-10-04T17:26:46.123Z,1349371606.122 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:46.181Z,1349371606.181 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:46.291Z,1349371606.291 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=22
2012-10-04T17:26:46.436Z,1349371606.436 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=26
2012-10-04T17:26:46.631Z,1349371606.631 [DVL_micro](DEBUG): RSSI read bytes: 1498 of 1660, #buffered=0
2012-10-04T17:26:46.647Z,1349371606.647 [DVL_micro](DEBUG): RSSI read bytes: 162 of 162, #buffered=798
2012-10-04T17:26:46.724Z,1349371606.724 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4
2012-10-04T17:26:46.806Z,1349371606.806 [NAL9602](INFO): Powering down
2012-10-04T17:26:46.963Z,1349371606.963 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:46.992Z,1349371606.992 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:47.167Z,1349371607.167 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=50
2012-10-04T17:26:47.344Z,1349371607.344 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:26:47.528Z,1349371607.528 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=58
2012-10-04T17:26:47.703Z,1349371607.703 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:47.959Z,1349371607.959 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:47.987Z,1349371607.987 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:48.162Z,1349371608.162 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=16
2012-10-04T17:26:48.340Z,1349371608.339 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:48.520Z,1349371608.520 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=24
2012-10-04T17:26:48.699Z,1349371608.699 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:48.959Z,1349371608.959 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:48.995Z,1349371608.995 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:49.159Z,1349371609.159 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:26:49.342Z,1349371609.342 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=38
2012-10-04T17:26:49.417Z,1349371609.417 [Reporter](INFO): Turbulence_NPS.packetNum 4 count
2012-10-04T17:26:49.519Z,1349371609.519 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=26
2012-10-04T17:26:49.700Z,1349371609.700 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:49.817Z,1349371609.817 [Reporter](INFO): Turbulence_NPS.packetNum 10 count
2012-10-04T17:26:49.955Z,1349371609.955 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:49.979Z,1349371609.979 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:50.161Z,1349371610.161 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=82
2012-10-04T17:26:50.239Z,1349371610.239 [Reporter](INFO): Turbulence_NPS.packetNum 17 count
2012-10-04T17:26:50.331Z,1349371610.331 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:26:50.515Z,1349371610.515 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=58
2012-10-04T17:26:50.650Z,1349371610.650 [Reporter](INFO): Turbulence_NPS.packetNum 24 count
2012-10-04T17:26:50.692Z,1349371610.692 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:50.947Z,1349371610.947 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:50.978Z,1349371610.978 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:51.100Z,1349371611.100 [Reporter](INFO): Turbulence_NPS.packetNum 31 count
2012-10-04T17:26:51.155Z,1349371611.155 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=81
2012-10-04T17:26:51.327Z,1349371611.327 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:26:51.512Z,1349371611.511 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=57
2012-10-04T17:26:51.530Z,1349371611.530 [Reporter](INFO): Turbulence_NPS.packetNum 38 count
2012-10-04T17:26:51.687Z,1349371611.687 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:51.838Z,1349371611.838 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8
2012-10-04T17:26:51.891Z,1349371611.891 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28
2012-10-04T17:26:51.921Z,1349371611.921 [Reporter](INFO): Turbulence_NPS.packetNum 44 count
2012-10-04T17:26:51.943Z,1349371611.943 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16
2012-10-04T17:26:51.999Z,1349371611.999 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2012-10-04T17:26:52.283Z,1349371612.283 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=25
2012-10-04T17:26:52.328Z,1349371612.328 [Reporter](INFO): Turbulence_NPS.packetNum 50 count
2012-10-04T17:26:52.387Z,1349371612.388 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29
2012-10-04T17:26:52.488Z,1349371612.488 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1
2012-10-04T17:26:52.592Z,1349371612.592 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2012-10-04T17:26:52.727Z,1349371612.727 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8
2012-10-04T17:26:52.733Z,1349371612.733 [Reporter](INFO): Turbulence_NPS.packetNum 57 count
2012-10-04T17:26:52.784Z,1349371612.784 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=29
2012-10-04T17:26:52.839Z,1349371612.839 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=49
2012-10-04T17:26:52.895Z,1349371612.895 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2012-10-04T17:26:53.140Z,1349371613.140 [Reporter](INFO): Turbulence_NPS.packetNum 63 count
2012-10-04T17:26:53.179Z,1349371613.179 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24
2012-10-04T17:26:53.283Z,1349371613.283 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60
2012-10-04T17:26:53.383Z,1349371613.383 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0
2012-10-04T17:26:53.488Z,1349371613.488 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2012-10-04T17:26:53.614Z,1349371613.614 [Reporter](INFO): Turbulence_NPS.packetNum 71 count
2012-10-04T17:26:53.707Z,1349371613.707 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:53.738Z,1349371613.738 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:53.875Z,1349371613.875 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=35
2012-10-04T17:26:54.003Z,1349371614.003 [Reporter](INFO): Turbulence_NPS.packetNum 77 count
2012-10-04T17:26:54.019Z,1349371614.019 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=39
2012-10-04T17:26:54.163Z,1349371614.163 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=11
2012-10-04T17:26:54.307Z,1349371614.307 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4
2012-10-04T17:26:54.365Z,1349371614.365 [Reporter](INFO): Turbulence_NPS.packetNum 83 count
2012-10-04T17:26:54.551Z,1349371614.551 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:54.590Z,1349371614.590 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:54.754Z,1349371614.754 [Reporter](INFO): Turbulence_NPS.packetNum 89 count
2012-10-04T17:26:54.755Z,1349371614.755 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=48
2012-10-04T17:26:54.931Z,1349371614.931 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:55.118Z,1349371615.118 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=57
2012-10-04T17:26:55.163Z,1349371615.163 [Reporter](INFO): Turbulence_NPS.packetNum 96 count
2012-10-04T17:26:55.291Z,1349371615.291 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:55.539Z,1349371615.539 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:55.573Z,1349371615.573 [Reporter](INFO): Turbulence_NPS.packetNum 102 count
2012-10-04T17:26:55.595Z,1349371615.595 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:55.739Z,1349371615.739 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:26:55.919Z,1349371615.919 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:26:55.961Z,1349371615.961 [Reporter](INFO): Turbulence_NPS.packetNum 109 count
2012-10-04T17:26:56.107Z,1349371616.107 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=121
2012-10-04T17:26:56.279Z,1349371616.279 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:56.367Z,1349371616.367 [Reporter](INFO): Turbulence_NPS.packetNum 115 count
2012-10-04T17:26:56.530Z,1349371616.530 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:56.567Z,1349371616.567 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:56.736Z,1349371616.736 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=50
2012-10-04T17:26:56.762Z,1349371616.762 [Reporter](INFO): Turbulence_NPS.packetNum 121 count
2012-10-04T17:26:56.911Z,1349371616.911 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:26:57.095Z,1349371617.095 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=26
2012-10-04T17:26:57.184Z,1349371617.184 [Reporter](INFO): Turbulence_NPS.packetNum 128 count
2012-10-04T17:26:57.271Z,1349371617.271 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:57.531Z,1349371617.531 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:57.561Z,1349371617.561 [Reporter](INFO): Turbulence_NPS.packetNum 134 count
2012-10-04T17:26:57.574Z,1349371617.574 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:57.732Z,1349371617.731 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:26:57.911Z,1349371617.911 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:26:57.965Z,1349371617.965 [Reporter](INFO): Turbulence_NPS.packetNum 141 count
2012-10-04T17:26:58.091Z,1349371618.091 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=27
2012-10-04T17:26:58.271Z,1349371618.271 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:58.359Z,1349371618.359 [Reporter](INFO): Turbulence_NPS.packetNum 147 count
2012-10-04T17:26:58.527Z,1349371618.527 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:58.560Z,1349371618.560 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:58.728Z,1349371618.728 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:26:58.837Z,1349371618.837 [Reporter](INFO): Turbulence_NPS.packetNum 155 count
2012-10-04T17:26:58.907Z,1349371618.907 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=7
2012-10-04T17:26:59.088Z,1349371619.088 [CTD_NeilBrown](ERROR): Bad response:  -0.13
2012-10-04T17:26:59.089Z,1349371619.089 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=27
2012-10-04T17:26:59.171Z,1349371619.171 [AHRS_sp3003D](ERROR): readAccelVecBin UART error: serial timeout
2012-10-04T17:26:59.171Z,1349371619.171 [AHRS_sp3003D](ERROR): readAccelVecBin got 0x03E9A0
2012-10-04T17:26:59.171Z,1349371619.171 [AHRS_sp3003D](FAULT): Read Acceleration Vector Failure.
2012-10-04T17:26:59.171Z,1349371619.171 [AHRS_sp3003D] Communications Fault, FailCount= 1
2012-10-04T17:26:59.172Z,1349371619.172 [AHRS_sp3003D](ERROR): Communications Fault
2012-10-04T17:26:59.267Z,1349371619.267 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:26:59.518Z,1349371619.518 [DVL_micro](DEBUG): NQ1
2012-10-04T17:26:59.549Z,1349371619.549 [DVL_micro](DEBUG): ADCP
2012-10-04T17:26:59.719Z,1349371619.719 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=48
2012-10-04T17:26:59.832Z,1349371619.832 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D
2012-10-04T17:26:59.834Z,1349371619.834 [Reporter](INFO): Turbulence_NPS.packetNum 171 count
2012-10-04T17:26:59.896Z,1349371619.896 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:00.064Z,1349371620.064 [AHRS_sp3003D](INFO): Powering down
2012-10-04T17:27:00.079Z,1349371620.079 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=24
2012-10-04T17:27:00.255Z,1349371620.255 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:00.264Z,1349371620.264 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2012-10-04T17:27:00.264Z,1349371620.264 [AHRS_sp3003D] No Fault, FailCount= 1
2012-10-04T17:27:00.266Z,1349371620.266 [Reporter](INFO): Turbulence_NPS.packetNum 178 count
2012-10-04T17:27:00.515Z,1349371620.515 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:00.556Z,1349371620.556 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:00.574Z,1349371620.574 [Reporter](INFO): Turbulence_NPS.packetNum 182 count
2012-10-04T17:27:00.711Z,1349371620.711 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:00.891Z,1349371620.891 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:00.957Z,1349371620.957 [Reporter](INFO): Turbulence_NPS.packetNum 189 count
2012-10-04T17:27:01.075Z,1349371621.075 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=57
2012-10-04T17:27:01.251Z,1349371621.251 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:01.265Z,1349371621.265 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-10-04T17:27:01.397Z,1349371621.397 [Reporter](INFO): Turbulence_NPS.packetNum 196 count
2012-10-04T17:27:01.511Z,1349371621.511 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:01.539Z,1349371621.539 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:01.707Z,1349371621.707 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=16
2012-10-04T17:27:01.764Z,1349371621.764 [Reporter](INFO): Turbulence_NPS.packetNum 202 count
2012-10-04T17:27:01.887Z,1349371621.888 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:02.071Z,1349371622.071 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=24
2012-10-04T17:27:02.209Z,1349371622.209 [Reporter](INFO): Turbulence_NPS.packetNum 209 count
2012-10-04T17:27:02.247Z,1349371622.247 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:02.504Z,1349371622.504 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:02.531Z,1349371622.531 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:02.704Z,1349371622.704 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:02.722Z,1349371622.722 [Reporter](INFO): Turbulence_NPS.packetNum 217 count
2012-10-04T17:27:02.885Z,1349371622.885 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=38
2012-10-04T17:27:03.063Z,1349371623.063 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=26
2012-10-04T17:27:03.119Z,1349371623.119 [Reporter](INFO): Turbulence_NPS.packetNum 223 count
2012-10-04T17:27:03.247Z,1349371623.247 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:03.496Z,1349371623.496 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:03.540Z,1349371623.540 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:03.555Z,1349371623.555 [Reporter](INFO): Turbulence_NPS.packetNum 230 count
2012-10-04T17:27:03.700Z,1349371623.700 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=50
2012-10-04T17:27:03.875Z,1349371623.875 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=7
2012-10-04T17:27:04.042Z,1349371624.042 [Reporter](INFO): Turbulence_NPS.packetNum 238 count
2012-10-04T17:27:04.059Z,1349371624.059 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=59
2012-10-04T17:27:04.235Z,1349371624.235 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:04.402Z,1349371624.402 [Reporter](INFO): Turbulence_NPS.packetNum 244 count
2012-10-04T17:27:04.491Z,1349371624.491 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:04.519Z,1349371624.519 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:04.696Z,1349371624.695 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=47
2012-10-04T17:27:04.824Z,1349371624.824 [Reporter](INFO): Turbulence_NPS.packetNum 251 count
2012-10-04T17:27:04.871Z,1349371624.871 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=3
2012-10-04T17:27:05.055Z,1349371625.055 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=55
2012-10-04T17:27:05.208Z,1349371625.208 [Reporter](INFO): Turbulence_NPS.packetNum 257 count
2012-10-04T17:27:05.231Z,1349371625.231 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:05.487Z,1349371625.487 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:05.518Z,1349371625.518 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:05.691Z,1349371625.691 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=48
2012-10-04T17:27:05.696Z,1349371625.696 [Reporter](INFO): Turbulence_NPS.packetNum 265 count
2012-10-04T17:27:05.867Z,1349371625.867 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:06.047Z,1349371626.047 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=24
2012-10-04T17:27:06.074Z,1349371626.074 [Reporter](INFO): Turbulence_NPS.packetNum 271 count
2012-10-04T17:27:06.227Z,1349371626.227 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:06.483Z,1349371626.483 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:06.519Z,1349371626.519 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:06.683Z,1349371626.684 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:06.863Z,1349371626.863 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:06.998Z,1349371626.998 [Reporter](INFO): Turbulence_NPS.packetNum 286 count
2012-10-04T17:27:07.044Z,1349371627.044 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:07.223Z,1349371627.223 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:07.457Z,1349371627.457 [Reporter](INFO): Turbulence_NPS.packetNum 293 count
2012-10-04T17:27:07.479Z,1349371627.479 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:07.506Z,1349371627.506 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:07.679Z,1349371627.679 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=16
2012-10-04T17:27:07.859Z,1349371627.859 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=36
2012-10-04T17:27:07.869Z,1349371627.869 [Reporter](INFO): Turbulence_NPS.packetNum 299 count
2012-10-04T17:27:08.040Z,1349371628.040 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:08.219Z,1349371628.219 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:08.283Z,1349371628.283 [Reporter](INFO): Turbulence_NPS.packetNum 306 count
2012-10-04T17:27:08.471Z,1349371628.471 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:08.502Z,1349371628.501 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:08.672Z,1349371628.672 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:27:08.678Z,1349371628.678 [Reporter](INFO): Turbulence_NPS.packetNum 312 count
2012-10-04T17:27:08.852Z,1349371628.852 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:27:09.032Z,1349371629.032 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=26
2012-10-04T17:27:09.068Z,1349371629.068 [Reporter](INFO): Turbulence_NPS.packetNum 319 count
2012-10-04T17:27:09.211Z,1349371629.211 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:09.467Z,1349371629.467 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:09.481Z,1349371629.481 [Reporter](INFO): Turbulence_NPS.packetNum 325 count
2012-10-04T17:27:09.524Z,1349371629.524 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:09.667Z,1349371629.667 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:09.847Z,1349371629.847 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:09.901Z,1349371629.901 [Reporter](INFO): Turbulence_NPS.packetNum 332 count
2012-10-04T17:27:10.028Z,1349371630.028 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:10.207Z,1349371630.207 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:10.312Z,1349371630.312 [Reporter](INFO): Turbulence_NPS.packetNum 339 count
2012-10-04T17:27:10.463Z,1349371630.463 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:10.488Z,1349371630.489 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:10.663Z,1349371630.663 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:10.733Z,1349371630.733 [Reporter](INFO): Turbulence_NPS.packetNum 345 count
2012-10-04T17:27:10.843Z,1349371630.843 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=37
2012-10-04T17:27:11.024Z,1349371631.024 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:11.126Z,1349371631.126 [Reporter](INFO): Turbulence_NPS.packetNum 352 count
2012-10-04T17:27:11.203Z,1349371631.203 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:11.455Z,1349371631.455 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:11.494Z,1349371631.494 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:11.513Z,1349371631.513 [Reporter](INFO): Turbulence_NPS.packetNum 358 count
2012-10-04T17:27:11.659Z,1349371631.659 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=49
2012-10-04T17:27:11.838Z,1349371631.838 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:11.937Z,1349371631.937 [Reporter](INFO): Turbulence_NPS.packetNum 364 count
2012-10-04T17:27:12.020Z,1349371632.020 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=57
2012-10-04T17:27:12.195Z,1349371632.195 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:12.324Z,1349371632.324 [Reporter](INFO): Turbulence_NPS.packetNum 371 count
2012-10-04T17:27:12.451Z,1349371632.451 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:12.481Z,1349371632.481 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:12.651Z,1349371632.651 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:12.755Z,1349371632.755 [Reporter](INFO): Turbulence_NPS.packetNum 378 count
2012-10-04T17:27:12.831Z,1349371632.831 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=37
2012-10-04T17:27:13.011Z,1349371633.011 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:13.128Z,1349371633.128 [Reporter](INFO): Turbulence_NPS.packetNum 384 count
2012-10-04T17:27:13.191Z,1349371633.191 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:13.442Z,1349371633.443 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:13.468Z,1349371633.468 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:13.559Z,1349371633.559 [Reporter](INFO): Turbulence_NPS.packetNum 391 count
2012-10-04T17:27:13.643Z,1349371633.643 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=20
2012-10-04T17:27:13.823Z,1349371633.823 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=40
2012-10-04T17:27:13.939Z,1349371633.939 [Reporter](INFO): Turbulence_NPS.packetNum 397 count
2012-10-04T17:27:14.004Z,1349371634.003 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=28
2012-10-04T17:27:14.179Z,1349371634.179 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:14.332Z,1349371634.332 [Reporter](INFO): Turbulence_NPS.packetNum 403 count
2012-10-04T17:27:14.443Z,1349371634.443 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:14.480Z,1349371634.480 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:14.643Z,1349371634.643 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:27:14.781Z,1349371634.781 [Reporter](INFO): Turbulence_NPS.packetNum 410 count
2012-10-04T17:27:14.823Z,1349371634.823 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:27:15.004Z,1349371635.004 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=26
2012-10-04T17:27:15.183Z,1349371635.183 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:15.193Z,1349371635.193 [Reporter](INFO): Turbulence_NPS.packetNum 417 count
2012-10-04T17:27:15.439Z,1349371635.439 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:15.482Z,1349371635.482 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:15.607Z,1349371635.607 [Reporter](INFO): Turbulence_NPS.packetNum 423 count
2012-10-04T17:27:15.639Z,1349371635.639 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=48
2012-10-04T17:27:15.815Z,1349371635.815 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:15.999Z,1349371635.999 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=56
2012-10-04T17:27:16.024Z,1349371636.024 [Reporter](INFO): Turbulence_NPS.packetNum 430 count
2012-10-04T17:27:16.176Z,1349371636.176 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:16.427Z,1349371636.427 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:16.437Z,1349371636.437 [Reporter](INFO): Turbulence_NPS.packetNum 437 count
2012-10-04T17:27:16.488Z,1349371636.488 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:16.627Z,1349371636.627 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=15
2012-10-04T17:27:16.807Z,1349371636.807 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=3
2012-10-04T17:27:16.905Z,1349371636.905 [Reporter](INFO): Turbulence_NPS.packetNum 444 count
2012-10-04T17:27:16.989Z,1349371636.989 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=23
2012-10-04T17:27:17.170Z,1349371637.170 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:17.303Z,1349371637.303 [Reporter](INFO): Turbulence_NPS.packetNum 451 count
2012-10-04T17:27:17.419Z,1349371637.419 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:17.451Z,1349371637.451 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:17.611Z,1349371637.611 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=0
2012-10-04T17:27:17.692Z,1349371637.691 [Reporter](INFO): Turbulence_NPS.packetNum 457 count
2012-10-04T17:27:17.787Z,1349371637.787 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=36
2012-10-04T17:27:17.960Z,1349371637.960 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=8
2012-10-04T17:27:18.082Z,1349371638.082 [Reporter](INFO): Turbulence_NPS.packetNum 463 count
2012-10-04T17:27:18.131Z,1349371638.131 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=4
2012-10-04T17:27:18.411Z,1349371638.411 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:18.464Z,1349371638.464 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:18.511Z,1349371638.511 [Reporter](INFO): Turbulence_NPS.packetNum 470 count
2012-10-04T17:27:18.615Z,1349371638.615 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=94
2012-10-04T17:27:18.779Z,1349371638.779 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=3
2012-10-04T17:27:18.885Z,1349371638.885 [Reporter](INFO): Turbulence_NPS.packetNum 476 count
2012-10-04T17:27:18.952Z,1349371638.952 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=7
2012-10-04T17:27:19.127Z,1349371639.127 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=4
2012-10-04T17:27:19.272Z,1349371639.272 [Reporter](INFO): Turbulence_NPS.packetNum 482 count
2012-10-04T17:27:19.411Z,1349371639.411 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:19.438Z,1349371639.438 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:19.607Z,1349371639.607 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=62
2012-10-04T17:27:19.732Z,1349371639.732 [Reporter](INFO): Turbulence_NPS.packetNum 490 count
2012-10-04T17:27:19.775Z,1349371639.775 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=2
2012-10-04T17:27:19.951Z,1349371639.951 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=38
2012-10-04T17:27:20.123Z,1349371640.123 [DVL_micro](DEBUG): RSSI read bytes: 1980 of 1980, #buffered=4
2012-10-04T17:27:20.158Z,1349371640.158 [Reporter](INFO): Turbulence_NPS.packetNum 496 count
2012-10-04T17:27:20.407Z,1349371640.407 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:20.457Z,1349371640.457 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:20.550Z,1349371640.550 [Reporter](INFO): Turbulence_NPS.packetNum 503 count
2012-10-04T17:27:20.607Z,1349371640.607 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=15
2012-10-04T17:27:20.787Z,1349371640.787 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=3
2012-10-04T17:27:20.934Z,1349371640.934 [Reporter](INFO): Turbulence_NPS.packetNum 509 count
2012-10-04T17:27:20.967Z,1349371640.967 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=23
2012-10-04T17:27:21.147Z,1349371641.147 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:21.328Z,1349371641.328 [Reporter](INFO): Turbulence_NPS.packetNum 515 count
2012-10-04T17:27:21.399Z,1349371641.399 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:21.437Z,1349371641.437 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:21.603Z,1349371641.603 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=48
2012-10-04T17:27:21.745Z,1349371641.745 [Reporter](INFO): Turbulence_NPS.packetNum 522 count
2012-10-04T17:27:21.779Z,1349371641.779 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:21.963Z,1349371641.963 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=56
2012-10-04T17:27:22.144Z,1349371642.144 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:22.178Z,1349371642.178 [Reporter](INFO): Turbulence_NPS.packetNum 529 count
2012-10-04T17:27:22.399Z,1349371642.399 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:22.436Z,1349371642.436 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:22.556Z,1349371642.556 [Reporter](INFO): Turbulence_NPS.packetNum 535 count
2012-10-04T17:27:22.599Z,1349371642.599 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=16
2012-10-04T17:27:22.783Z,1349371642.783 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=36
2012-10-04T17:27:22.959Z,1349371642.959 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=24
2012-10-04T17:27:22.974Z,1349371642.974 [Reporter](INFO): Turbulence_NPS.packetNum 542 count
2012-10-04T17:27:23.139Z,1349371643.139 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:23.379Z,1349371643.379 [Reporter](INFO): Turbulence_NPS.packetNum 548 count
2012-10-04T17:27:23.391Z,1349371643.391 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:23.437Z,1349371643.437 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:23.600Z,1349371643.601 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=47
2012-10-04T17:27:23.775Z,1349371643.775 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=35
2012-10-04T17:27:23.821Z,1349371643.821 [Reporter](INFO): Turbulence_NPS.packetNum 555 count
2012-10-04T17:27:23.955Z,1349371643.955 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=56
2012-10-04T17:27:24.131Z,1349371644.131 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:24.251Z,1349371644.251 [Reporter](INFO): Turbulence_NPS.packetNum 562 count
2012-10-04T17:27:24.383Z,1349371644.383 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:24.430Z,1349371644.430 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:24.588Z,1349371644.588 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=48
2012-10-04T17:27:24.608Z,1349371644.608 [Reporter](INFO): Turbulence_NPS.packetNum 568 count
2012-10-04T17:27:24.763Z,1349371644.763 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:24.947Z,1349371644.947 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=56
2012-10-04T17:27:25.013Z,1349371645.013 [Reporter](INFO): Turbulence_NPS.packetNum 574 count
2012-10-04T17:27:25.123Z,1349371645.123 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:25.383Z,1349371645.383 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:25.414Z,1349371645.414 [Reporter](INFO): Turbulence_NPS.packetNum 581 count
2012-10-04T17:27:25.432Z,1349371645.432 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:25.584Z,1349371645.584 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=51
2012-10-04T17:27:25.760Z,1349371645.760 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=7
2012-10-04T17:27:25.814Z,1349371645.814 [Reporter](INFO): Turbulence_NPS.packetNum 587 count
2012-10-04T17:27:25.943Z,1349371645.943 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=59
2012-10-04T17:27:26.119Z,1349371646.119 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:26.255Z,1349371646.255 [Reporter](INFO): Turbulence_NPS.packetNum 594 count
2012-10-04T17:27:26.375Z,1349371646.375 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:26.416Z,1349371646.416 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:26.580Z,1349371646.580 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=49
2012-10-04T17:27:26.619Z,1349371646.619 [Reporter](INFO): Turbulence_NPS.packetNum 600 count
2012-10-04T17:27:26.759Z,1349371646.759 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=37
2012-10-04T17:27:26.939Z,1349371646.939 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=57
2012-10-04T17:27:27.063Z,1349371647.063 [Reporter](INFO): Turbulence_NPS.packetNum 607 count
2012-10-04T17:27:27.118Z,1349371647.118 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:27.367Z,1349371647.367 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:27.407Z,1349371647.407 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:27.501Z,1349371647.501 [Reporter](INFO): Turbulence_NPS.packetNum 614 count
2012-10-04T17:27:27.571Z,1349371647.571 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=50
2012-10-04T17:27:27.747Z,1349371647.747 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:27:27.886Z,1349371647.885 [Reporter](INFO): Turbulence_NPS.packetNum 620 count
2012-10-04T17:27:27.931Z,1349371647.931 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=58
2012-10-04T17:27:28.107Z,1349371648.107 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:28.299Z,1349371648.299 [Reporter](INFO): Turbulence_NPS.packetNum 627 count
2012-10-04T17:27:28.363Z,1349371648.363 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:28.396Z,1349371648.396 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:28.563Z,1349371648.563 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:28.693Z,1349371648.694 [Reporter](INFO): Turbulence_NPS.packetNum 633 count
2012-10-04T17:27:28.743Z,1349371648.743 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:28.927Z,1349371648.927 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=57
2012-10-04T17:27:29.094Z,1349371649.094 [Reporter](INFO): Turbulence_NPS.packetNum 640 count
2012-10-04T17:27:29.106Z,1349371649.106 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:29.359Z,1349371649.359 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:29.388Z,1349371649.388 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:29.503Z,1349371649.503 [Reporter](INFO): Turbulence_NPS.packetNum 646 count
2012-10-04T17:27:29.560Z,1349371649.560 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=15
2012-10-04T17:27:29.739Z,1349371649.739 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=35
2012-10-04T17:27:29.900Z,1349371649.900 [Reporter](INFO): Turbulence_NPS.packetNum 653 count
2012-10-04T17:27:29.923Z,1349371649.923 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=55
2012-10-04T17:27:30.099Z,1349371650.099 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:30.292Z,1349371650.293 [Reporter](INFO): Turbulence_NPS.packetNum 659 count
2012-10-04T17:27:30.355Z,1349371650.355 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:30.383Z,1349371650.383 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:30.555Z,1349371650.555 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:27:30.735Z,1349371650.735 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=7
2012-10-04T17:27:30.786Z,1349371650.786 [Reporter](INFO): Turbulence_NPS.packetNum 667 count
2012-10-04T17:27:30.915Z,1349371650.915 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=27
2012-10-04T17:27:31.095Z,1349371651.095 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:31.139Z,1349371651.139 [Reporter](INFO): Turbulence_NPS.packetNum 672 count
2012-10-04T17:27:31.351Z,1349371651.351 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:31.377Z,1349371651.378 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:31.525Z,1349371651.526 [Reporter](INFO): Turbulence_NPS.packetNum 678 count
2012-10-04T17:27:31.552Z,1349371651.552 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:27:31.731Z,1349371651.731 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=39
2012-10-04T17:27:31.911Z,1349371651.911 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=27
2012-10-04T17:27:31.930Z,1349371651.930 [Reporter](INFO): Turbulence_NPS.packetNum 685 count
2012-10-04T17:27:32.087Z,1349371652.087 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:32.337Z,1349371652.337 [Reporter](INFO): Turbulence_NPS.packetNum 692 count
2012-10-04T17:27:32.343Z,1349371652.343 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:32.371Z,1349371652.371 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:32.547Z,1349371652.547 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=50
2012-10-04T17:27:32.724Z,1349371652.724 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=7
2012-10-04T17:27:32.737Z,1349371652.737 [Reporter](INFO): Turbulence_NPS.packetNum 698 count
2012-10-04T17:27:32.907Z,1349371652.907 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=59
2012-10-04T17:27:33.087Z,1349371653.088 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:33.156Z,1349371653.156 [Reporter](INFO): Turbulence_NPS.packetNum 705 count
2012-10-04T17:27:33.339Z,1349371653.339 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:33.367Z,1349371653.367 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:33.534Z,1349371653.534 [Reporter](INFO): Turbulence_NPS.packetNum 710 count
2012-10-04T17:27:33.539Z,1349371653.539 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=19
2012-10-04T17:27:33.719Z,1349371653.719 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=7
2012-10-04T17:27:33.899Z,1349371653.899 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=28
2012-10-04T17:27:33.933Z,1349371653.933 [Reporter](INFO): Turbulence_NPS.packetNum 717 count
2012-10-04T17:27:34.085Z,1349371654.085 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:34.335Z,1349371654.335 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:34.330Z,1349371654.330 [Reporter](INFO): Turbulence_NPS.packetNum 723 count
2012-10-04T17:27:34.364Z,1349371654.364 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:34.536Z,1349371654.536 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=50
2012-10-04T17:27:34.712Z,1349371654.712 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:27:34.762Z,1349371654.762 [Reporter](INFO): Turbulence_NPS.packetNum 730 count
2012-10-04T17:27:34.895Z,1349371654.895 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=26
2012-10-04T17:27:35.071Z,1349371655.071 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:35.148Z,1349371655.148 [Reporter](INFO): Turbulence_NPS.packetNum 737 count
2012-10-04T17:27:35.329Z,1349371655.329 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:35.355Z,1349371655.355 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:35.527Z,1349371655.527 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=19
2012-10-04T17:27:35.537Z,1349371655.537 [Reporter](INFO): Turbulence_NPS.packetNum 743 count
2012-10-04T17:27:35.707Z,1349371655.707 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=7
2012-10-04T17:27:35.898Z,1349371655.898 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=91
2012-10-04T17:27:35.967Z,1349371655.967 [Reporter](INFO): Turbulence_NPS.packetNum 750 count
2012-10-04T17:27:36.067Z,1349371656.067 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:36.323Z,1349371656.323 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:36.355Z,1349371656.355 [Reporter](INFO): Turbulence_NPS.packetNum 756 count
2012-10-04T17:27:36.365Z,1349371656.365 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:36.523Z,1349371656.523 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:27:36.704Z,1349371656.704 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:27:36.756Z,1349371656.756 [Reporter](INFO): Turbulence_NPS.packetNum 762 count
2012-10-04T17:27:36.883Z,1349371656.883 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=26
2012-10-04T17:27:37.063Z,1349371657.063 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:37.155Z,1349371657.155 [Reporter](INFO): Turbulence_NPS.packetNum 769 count
2012-10-04T17:27:37.319Z,1349371657.319 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:37.345Z,1349371657.345 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:37.518Z,1349371657.518 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=18
2012-10-04T17:27:37.539Z,1349371657.539 [Reporter](INFO): Turbulence_NPS.packetNum 775 count
2012-10-04T17:27:37.699Z,1349371657.699 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=6
2012-10-04T17:27:37.883Z,1349371657.883 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=58
2012-10-04T17:27:37.981Z,1349371657.981 [Reporter](INFO): Turbulence_NPS.packetNum 782 count
2012-10-04T17:27:38.061Z,1349371658.061 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:38.316Z,1349371658.316 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:38.344Z,1349371658.344 [Reporter](INFO): Turbulence_NPS.packetNum 788 count
2012-10-04T17:27:38.363Z,1349371658.363 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:38.515Z,1349371658.515 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:38.692Z,1349371658.692 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:38.756Z,1349371658.756 [Reporter](INFO): Turbulence_NPS.packetNum 794 count
2012-10-04T17:27:38.876Z,1349371658.875 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:39.051Z,1349371659.051 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:39.155Z,1349371659.155 [Reporter](INFO): Turbulence_NPS.packetNum 801 count
2012-10-04T17:27:39.307Z,1349371659.307 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:39.339Z,1349371659.339 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:39.508Z,1349371659.509 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:39.569Z,1349371659.569 [Reporter](INFO): Turbulence_NPS.packetNum 807 count
2012-10-04T17:27:39.689Z,1349371659.689 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:39.868Z,1349371659.868 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:39.985Z,1349371659.985 [Reporter](INFO): Turbulence_NPS.packetNum 814 count
2012-10-04T17:27:40.047Z,1349371660.047 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:40.303Z,1349371660.303 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:40.332Z,1349371660.332 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:40.503Z,1349371660.503 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=16
2012-10-04T17:27:40.683Z,1349371660.683 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=36
2012-10-04T17:27:40.863Z,1349371660.863 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:41.043Z,1349371661.043 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:41.181Z,1349371661.181 [Reporter](INFO): Turbulence_NPS.packetNum 833 count
2012-10-04T17:27:41.294Z,1349371661.295 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:41.335Z,1349371661.335 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:41.499Z,1349371661.499 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=48
2012-10-04T17:27:41.580Z,1349371661.580 [Reporter](INFO): Turbulence_NPS.packetNum 840 count
2012-10-04T17:27:41.675Z,1349371661.675 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:41.859Z,1349371661.859 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=24
2012-10-04T17:27:41.953Z,1349371661.953 [Reporter](INFO): Turbulence_NPS.packetNum 846 count
2012-10-04T17:27:42.035Z,1349371662.035 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:42.291Z,1349371662.291 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:42.324Z,1349371662.324 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:42.396Z,1349371662.396 [Reporter](INFO): Turbulence_NPS.packetNum 853 count
2012-10-04T17:27:42.492Z,1349371662.492 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=17
2012-10-04T17:27:42.671Z,1349371662.671 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=5
2012-10-04T17:27:42.775Z,1349371662.775 [Reporter](INFO): Turbulence_NPS.packetNum 859 count
2012-10-04T17:27:42.855Z,1349371662.855 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=57
2012-10-04T17:27:43.031Z,1349371663.031 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:43.176Z,1349371663.176 [Reporter](INFO): Turbulence_NPS.packetNum 865 count
2012-10-04T17:27:43.287Z,1349371663.287 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:43.328Z,1349371663.328 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:43.487Z,1349371663.487 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=16
2012-10-04T17:27:43.580Z,1349371663.580 [Reporter](INFO): Turbulence_NPS.packetNum 872 count
2012-10-04T17:27:43.667Z,1349371663.667 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=37
2012-10-04T17:27:43.848Z,1349371663.848 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:43.968Z,1349371663.968 [Reporter](INFO): Turbulence_NPS.packetNum 878 count
2012-10-04T17:27:44.028Z,1349371664.028 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:44.283Z,1349371664.283 [DVL_micro](DEBUG): NQ1
2012-10-04T17:27:44.330Z,1349371664.330 [DVL_micro](DEBUG): ADCP
2012-10-04T17:27:44.395Z,1349371664.395 [Reporter](INFO): Turbulence_NPS.packetNum 885 count
2012-10-04T17:27:44.483Z,1349371664.483 [CommandLine](IMPORTANT): got command stop
2012-10-04T17:27:44.484Z,1349371664.484 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=16
2012-10-04T17:27:44.663Z,1349371664.663 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=36
2012-10-04T17:27:44.736Z,1349371664.736 [science_to_67_70] Stopped
2012-10-04T17:27:44.736Z,1349371664.736 [science_to_67_70](INFO): Aggregate::uninitialize science_to_67_70
2012-10-04T17:27:44.736Z,1349371664.736 [science_to_67_70:AltEnvWrapper] Stopped
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:AltEnvWrapper](INFO): Aggregate::uninitialize science_to_67_70:AltEnvWrapper
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:AltEnvWrapper:A.AltitudeEnvelope] Stopped
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:AltEnvWrapper:B.Wait] Stopped
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:AltEnvWrapper:B.Wait](DEBUG): Uninitialize Wait Component.
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:B.DepthEnvelope] Stopped
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:B.DepthEnvelope](DEBUG): Uninitialize.
2012-10-04T17:27:44.737Z,1349371664.737 [science_to_67_70:OffshoreWrapper] Stopped
2012-10-04T17:27:44.738Z,1349371664.737 [science_to_67_70:OffshoreWrapper](INFO): Aggregate::uninitialize science_to_67_70:OffshoreWrapper
2012-10-04T17:27:44.738Z,1349371664.738 [science_to_67_70:OffshoreWrapper:A.OffshoreEnvelope] Stopped
2012-10-04T17:27:44.738Z,1349371664.738 [science_to_67_70:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2012-10-04T17:27:44.738Z,1349371664.738 [science_to_67_70:OffshoreWrapper:B.Wait] Stopped
2012-10-04T17:27:44.738Z,1349371664.738 [science_to_67_70:OffshoreWrapper:B.Wait](DEBUG): Uninitialize Wait Component.
2012-10-04T17:27:44.738Z,1349371664.738 [science_to_67_70:Science] Stopped
2012-10-04T17:27:44.739Z,1349371664.739 [science_to_67_70:Science](INFO): Aggregate::uninitialize science_to_67_70:Science
2012-10-04T17:27:44.739Z,1349371664.739 [science_to_67_70:Science:A] Stopped
2012-10-04T17:27:44.739Z,1349371664.739 [science_to_67_70:Science:B] Stopped
2012-10-04T17:27:44.739Z,1349371664.739 [science_to_67_70:Science:C] Stopped
2012-10-04T17:27:44.739Z,1349371664.740 [science_to_67_70:Science:D] Stopped
2012-10-04T17:27:44.739Z,1349371664.740 [science_to_67_70:Science:E] Stopped
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:Science:F] Stopped
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:Science:G] Stopped
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:Science:PeakDetectChl] Stopped
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:Science:PeakDetectChl](INFO): Aggregate::uninitialize science_to_67_70:Science:PeakDetectChl
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:G.Buoyancy] Stopped
2012-10-04T17:27:44.740Z,1349371664.740 [science_to_67_70:G.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2012-10-04T17:27:44.741Z,1349371664.741 [science_to_67_70:H.SetSpeed] Stopped
2012-10-04T17:27:44.741Z,1349371664.741 [science_to_67_70:H.SetSpeed](DEBUG): Uninitialize.
2012-10-04T17:27:44.741Z,1349371664.741 [science_to_67_70:I.DepthEnvelope] Stopped
2012-10-04T17:27:44.741Z,1349371664.741 [science_to_67_70:I.DepthEnvelope](DEBUG): Uninitialize.
2012-10-04T17:27:44.741Z,1349371664.741 [science_to_67_70:J.YoYo] Stopped
2012-10-04T17:27:44.741Z,1349371664.741 [science_to_67_70:J.YoYo](DEBUG): Uninitialize YoYoComponent.
2012-10-04T17:27:44.741Z,1349371664.741 [science_to_67_70:Wpt.Point] Stopped
2012-10-04T17:27:44.753Z,1349371664.753 [Turbulence_NPS](INFO): Pause powering down
2012-10-04T17:27:44.836Z,1349371664.836 [Reporter](INFO): Turbulence_NPS.packetNum no_value
2012-10-04T17:27:44.839Z,1349371664.839 [WetLabsBB2FL](INFO): Powering down
2012-10-04T17:27:44.843Z,1349371664.843 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=25
2012-10-04T17:27:45.019Z,1349371665.019 [DVL_micro](DEBUG): RSSI read bytes: 2060 of 2060, #buffered=4
2012-10-04T17:27:45.034Z,1349371665.034 [DVL_micro](INFO): pause:Powering down
2012-10-04T17:27:45.289Z,1349371665.289 [MissionManager](IMPORTANT): Started mission Default
2012-10-04T17:27:45.289Z,1349371665.289 [Default] Running Loop=1
2012-10-04T17:27:45.289Z,1349371665.289 [Default](INFO): Aggregate::initialize Default
2012-10-04T17:27:45.289Z,1349371665.289 [Default:D.SetSpeed] Running Loop=1
2012-10-04T17:27:45.289Z,1349371665.289 [Default:D.SetSpeed](DEBUG): Initialize.
2012-10-04T17:27:45.289Z,1349371665.289 [Default:E.GoToSurface] Running Loop=1
2012-10-04T17:27:45.289Z,1349371665.289 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-04T17:27:45.290Z,1349371665.290 [Default:Iridium] Running Loop=1
2012-10-04T17:27:45.290Z,1349371665.290 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-10-04T17:27:45.290Z,1349371665.290 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-04T17:27:45.290Z,1349371665.290 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-10-04T17:27:45.290Z,1349371665.290 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-10-04T17:27:45.290Z,1349371665.290 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-04T17:27:45.292Z,1349371665.292 [Default:Iridium:B.GoToSurface] Stopped
2012-10-04T17:27:45.292Z,1349371665.292 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-04T17:27:45.292Z,1349371665.293 [Default:Iridium:Read_Iridium] Running Loop=1
2012-10-04T17:27:46.084Z,1349371666.084 [NAL9602](INFO): Powering up