2013-09-16T20:49:32.041Z,1379364572.041 [Supervisor](DEBUG): Initializing supervisor.
2013-09-16T20:49:32.044Z,1379364572.044 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-09-16T20:49:32.044Z,1379364572.044 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-09-16T20:49:32.045Z,1379364572.045 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-09-16T20:49:32.048Z,1379364572.048 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-09-16T20:49:32.059Z,1379364572.059 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-09-16T20:49:32.060Z,1379364572.060 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-09-16T20:49:32.061Z,1379364572.061 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-09-16T20:49:32.062Z,1379364572.062 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-09-16T20:49:32.062Z,1379364572.062 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-09-16T20:49:32.064Z,1379364572.064 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-09-16T20:49:32.444Z,1379364572.444 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-09-16T20:49:32.444Z,1379364572.444 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-09-16T20:49:32.637Z,1379364572.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-09-16T20:49:32.637Z,1379364572.637 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-09-16T20:49:32.723Z,1379364572.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-09-16T20:49:32.723Z,1379364572.723 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-09-16T20:49:32.835Z,1379364572.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-09-16T20:49:32.836Z,1379364572.836 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-09-16T20:49:32.979Z,1379364572.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-09-16T20:49:32.980Z,1379364572.980 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-09-16T20:49:33.218Z,1379364573.218 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-09-16T20:49:33.219Z,1379364573.219 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-09-16T20:49:33.383Z,1379364573.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-09-16T20:49:33.384Z,1379364573.384 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-09-16T20:49:33.647Z,1379364573.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-09-16T20:49:33.647Z,1379364573.647 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-09-16T20:49:33.749Z,1379364573.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-09-16T20:49:33.750Z,1379364573.750 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-09-16T20:49:34.163Z,1379364574.163 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-09-16T20:49:34.164Z,1379364574.164 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-09-16T20:49:34.275Z,1379364574.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-09-16T20:49:34.275Z,1379364574.275 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-09-16T20:49:34.362Z,1379364574.362 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-09-16T20:49:34.363Z,1379364574.363 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-09-16T20:49:34.460Z,1379364574.460 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-09-16T20:49:34.586Z,1379364574.586 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-09-16T20:49:34.682Z,1379364574.682 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-09-16T20:49:34.787Z,1379364574.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-09-16T20:49:34.884Z,1379364574.884 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-09-16T20:49:34.998Z,1379364574.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-09-16T20:49:35.094Z,1379364575.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-09-16T20:49:35.181Z,1379364575.181 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2013-09-16T20:49:35.181Z,1379364575.181 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-09-16T20:49:35.185Z,1379364575.185 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-09-16T20:49:35.344Z,1379364575.344 [InternalSim] Loaded
2013-09-16T20:49:35.344Z,1379364575.344 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-09-16T20:49:35.345Z,1379364575.345 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-09-16T20:49:35.345Z,1379364575.345 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-09-16T20:49:35.429Z,1379364575.429 [SBIT](DEBUG): Construct Startup Built In Test.
2013-09-16T20:49:35.458Z,1379364575.458 [SBIT] Loaded
2013-09-16T20:49:35.458Z,1379364575.458 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-09-16T20:49:35.458Z,1379364575.458 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-09-16T20:49:35.487Z,1379364575.487 [IBIT] Loaded
2013-09-16T20:49:35.488Z,1379364575.488 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-09-16T20:49:35.490Z,1379364575.490 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-09-16T20:49:35.602Z,1379364575.602 [CBIT] Loaded
2013-09-16T20:49:35.603Z,1379364575.603 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-09-16T20:49:35.603Z,1379364575.603 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-09-16T20:49:35.604Z,1379364575.604 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-09-16T20:49:35.763Z,1379364575.763 [ElevatorServo] Loaded
2013-09-16T20:49:35.763Z,1379364575.763 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-09-16T20:49:35.775Z,1379364575.775 [MassServo] Loaded
2013-09-16T20:49:35.775Z,1379364575.775 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-09-16T20:49:35.786Z,1379364575.786 [RudderServo] Loaded
2013-09-16T20:49:35.786Z,1379364575.786 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-09-16T20:49:35.797Z,1379364575.797 [ThrusterServo] Loaded
2013-09-16T20:49:35.798Z,1379364575.798 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-09-16T20:49:35.798Z,1379364575.798 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-09-16T20:49:35.799Z,1379364575.799 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-09-16T20:49:35.832Z,1379364575.832 [DepthRateCalculator] Loaded
2013-09-16T20:49:35.833Z,1379364575.833 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-09-16T20:49:38.794Z,1379364578.794 [HFRadarModelCalc] Loaded
2013-09-16T20:49:38.795Z,1379364578.795 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-09-16T20:49:38.810Z,1379364578.810 [NavChart] Loaded
2013-09-16T20:49:38.810Z,1379364578.810 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-09-16T20:49:38.816Z,1379364578.816 [PitchRateCalculator] Loaded
2013-09-16T20:49:38.816Z,1379364578.816 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-09-16T20:49:38.827Z,1379364578.827 [SpeedCalculator] Loaded
2013-09-16T20:49:38.827Z,1379364578.827 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-09-16T20:49:38.843Z,1379364578.843 [TempGradientCalculator] Loaded
2013-09-16T20:49:38.843Z,1379364578.843 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-09-16T20:49:38.849Z,1379364578.849 [YawRateCalculator] Loaded
2013-09-16T20:49:38.849Z,1379364578.849 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-09-16T20:49:38.895Z,1379364578.895 [Navigation] Loaded
2013-09-16T20:49:38.895Z,1379364578.895 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-09-16T20:49:38.896Z,1379364578.896 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-09-16T20:49:38.896Z,1379364578.896 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-09-16T20:49:39.128Z,1379364579.128 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-09-16T20:49:39.128Z,1379364579.128 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-09-16T20:49:39.151Z,1379364579.151 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-09-16T20:49:39.151Z,1379364579.151 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-09-16T20:49:39.197Z,1379364579.197 [VerticalControl](DEBUG): Construct VerticalControl.
2013-09-16T20:49:39.292Z,1379364579.292 [VerticalControl] Loaded
2013-09-16T20:49:39.292Z,1379364579.292 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-09-16T20:49:39.293Z,1379364579.293 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-09-16T20:49:39.351Z,1379364579.351 [HorizontalControl] Loaded
2013-09-16T20:49:39.351Z,1379364579.351 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-09-16T20:49:39.352Z,1379364579.352 [SpeedControl](DEBUG): Construct SpeedControl.
2013-09-16T20:49:39.353Z,1379364579.353 [SpeedControl] Loaded
2013-09-16T20:49:39.354Z,1379364579.354 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-09-16T20:49:39.354Z,1379364579.354 [LoopControl](DEBUG): Construct LoopControl.
2013-09-16T20:49:39.355Z,1379364579.355 [LoopControl] Loaded
2013-09-16T20:49:39.355Z,1379364579.355 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-09-16T20:49:39.356Z,1379364579.356 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-09-16T20:49:39.356Z,1379364579.356 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-09-16T20:49:39.362Z,1379364579.362 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-09-16T20:49:39.367Z,1379364579.367 [AsyncPiEstimator] Loaded
2013-09-16T20:49:39.367Z,1379364579.367 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-09-16T20:49:39.368Z,1379364579.368 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0
2013-09-16T20:49:39.369Z,1379364579.369 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-09-16T20:49:39.369Z,1379364579.369 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-09-16T20:49:39.559Z,1379364579.559 [AHRS_sp3003D] Loaded
2013-09-16T20:49:39.560Z,1379364579.560 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-09-16T20:49:39.573Z,1379364579.573 [Depth_Keller] Loaded
2013-09-16T20:49:39.574Z,1379364579.574 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-09-16T20:49:39.752Z,1379364579.752 [DVL_micro] Loaded
2013-09-16T20:49:39.753Z,1379364579.753 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-09-16T20:49:39.754Z,1379364579.754 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406CE4E0
2013-09-16T20:49:39.840Z,1379364579.840 [NAL9602] Loaded
2013-09-16T20:49:39.841Z,1379364579.841 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-09-16T20:49:39.882Z,1379364579.882 [Onboard] Loaded
2013-09-16T20:49:39.882Z,1379364579.882 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-09-16T20:49:39.889Z,1379364579.889 [Radio_Freewave] Loaded
2013-09-16T20:49:39.889Z,1379364579.889 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-09-16T20:49:40.030Z,1379364580.030 [DAT] Loaded
2013-09-16T20:49:40.030Z,1379364580.030 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-09-16T20:49:40.036Z,1379364580.036 [SCPI] Loaded
2013-09-16T20:49:40.037Z,1379364580.037 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2013-09-16T20:49:40.037Z,1379364580.037 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-09-16T20:49:40.038Z,1379364580.038 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-09-16T20:49:40.134Z,1379364580.134 [CTD_NeilBrown] Loaded
2013-09-16T20:49:40.134Z,1379364580.134 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-09-16T20:49:40.135Z,1379364580.135 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4072B4E0
2013-09-16T20:49:40.150Z,1379364580.150 [PAR_Licor] Loaded
2013-09-16T20:49:40.150Z,1379364580.150 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-09-16T20:49:40.182Z,1379364580.182 [WetLabsBB2FL] Loaded
2013-09-16T20:49:40.182Z,1379364580.182 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-09-16T20:49:40.183Z,1379364580.183 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4075B4E0
2013-09-16T20:49:40.184Z,1379364580.184 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-09-16T20:49:40.186Z,1379364580.186 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-09-16T20:49:40.187Z,1379364580.187 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-09-16T20:49:40.194Z,1379364580.194 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-09-16T20:49:40.195Z,1379364580.195 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2013-09-16T20:49:40.199Z,1379364580.199 [Supervisor](DEBUG): Running supervisor.
2013-09-16T20:49:40.200Z,1379364580.200 [CommandLine](INFO): Thread ID is 5397
2013-09-16T20:49:40.202Z,1379364580.202 [controlThread](INFO): Thread ID is 5396
2013-09-16T20:49:40.203Z,1379364580.203 [controlThread](DEBUG): Initializing ControlThread
2013-09-16T20:49:40.203Z,1379364580.203 [CycleStarter](INFO): Thread ID is 5395
2013-09-16T20:49:40.203Z,1379364580.203 [InternalSim](DEBUG):  InternalSim initializing...
2013-09-16T20:49:40.237Z,1379364580.237 [logger](INFO): Thread ID is 5398
2013-09-16T20:49:40.264Z,1379364580.264 [SBIT](INFO): Initialize SBIT Component.
2013-09-16T20:49:40.264Z,1379364580.264 [SBIT](IMPORTANT): Tethys CM Info: 
$Rev:10634
2013-09-16T20:49:40.265Z,1379364580.265 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-09-16T20:49:40.265Z,1379364580.265 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-09-16T20:49:40.266Z,1379364580.266 [IBIT](INFO): Initialize IBIT Component.
2013-09-16T20:49:40.266Z,1379364580.266 [CBIT](DEBUG): Initialize CBIT Component.
2013-09-16T20:49:40.267Z,1379364580.267 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-09-16T20:49:40.277Z,1379364580.277 [AsyncPiEstimator](INFO): Thread ID is 5459
2013-09-16T20:49:40.277Z,1379364580.277 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-09-16T20:49:40.291Z,1379364580.291 [DVL_micro](INFO): Thread ID is 5460
2013-09-16T20:49:40.293Z,1379364580.293 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-09-16T20:49:40.294Z,1379364580.294 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-09-16T20:49:40.294Z,1379364580.294 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-09-16T20:49:40.295Z,1379364580.295 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-09-16T20:49:40.295Z,1379364580.295 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-09-16T20:49:40.295Z,1379364580.295 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-09-16T20:49:40.296Z,1379364580.296 [Navigation](DEBUG): Initializing Navigation.
2013-09-16T20:49:40.296Z,1379364580.296 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-09-16T20:49:40.298Z,1379364580.298 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-09-16T20:49:40.299Z,1379364580.299 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-09-16T20:49:40.299Z,1379364580.299 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-09-16T20:49:40.304Z,1379364580.304 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-09-16T20:49:40.322Z,1379364580.322 [DVL_micro](INFO): Initializing
2013-09-16T20:49:40.322Z,1379364580.322 [DVL_micro](INFO): start:Powering up
2013-09-16T20:49:40.324Z,1379364580.324 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-16T20:49:40.326Z,1379364580.326 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-16T20:49:40.329Z,1379364580.329 [CTD_NeilBrown](INFO): Thread ID is 5461
2013-09-16T20:49:40.330Z,1379364580.330 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-09-16T20:49:40.331Z,1379364580.331 [DVL_micro](INFO): Cycling power to configure device.
2013-09-16T20:49:40.333Z,1379364580.333 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-09-16T20:49:40.334Z,1379364580.334 [WetLabsBB2FL](INFO): Thread ID is 5462
2013-09-16T20:49:40.335Z,1379364580.335 [WetLabsBB2FL](INFO): Powering down
2013-09-16T20:49:40.387Z,1379364580.387 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-09-16T20:49:40.388Z,1379364580.388 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-09-16T20:49:40.394Z,1379364580.394 [NavChartDb](INFO): Thread ID is 5463
2013-09-16T20:49:40.405Z,1379364580.405 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-09-16T20:49:40.406Z,1379364580.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-09-16T20:49:40.406Z,1379364580.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-09-16T20:49:40.406Z,1379364580.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-09-16T20:49:40.406Z,1379364580.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-09-16T20:49:40.407Z,1379364580.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-09-16T20:49:40.407Z,1379364580.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-09-16T20:49:40.407Z,1379364580.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-09-16T20:49:40.407Z,1379364580.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-09-16T20:49:40.495Z,1379364580.495 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-09-16T20:49:40.498Z,1379364580.498 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-09-16T20:49:40.506Z,1379364580.506 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-16T20:49:40.522Z,1379364580.522 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-09-16T20:49:40.530Z,1379364580.530 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-16T20:49:40.562Z,1379364580.562 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-09-16T20:49:40.592Z,1379364580.592 [Default:D.SetSpeed](DEBUG): Construct.
2013-09-16T20:49:40.595Z,1379364580.595 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-16T20:49:40.611Z,1379364580.611 [Default:F.Wait](DEBUG): Construct Wait.
2013-09-16T20:49:40.626Z,1379364580.626 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS" >

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

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium" >

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

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

        <Call RefId="Iridium"/>

    </Aggregate>

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

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

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

</Mission>


2013-09-16T20:49:40.631Z,1379364580.631 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,NAL9602,Onboard,Radio_Freewave,DAT,SCPI,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-09-16T20:49:40.697Z,1379364580.697 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-16T20:49:40.712Z,1379364580.712 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar
2013-09-16T20:49:40.794Z,1379364580.794 [Radio_Freewave](INFO): Powering up
2013-09-16T20:49:40.817Z,1379364580.817 [DAT](INFO): Powering up
2013-09-16T20:49:40.818Z,1379364580.818 [DAT](DEBUG): Initializing DAT.
2013-09-16T20:49:41.179Z,1379364581.179 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-09-16T20:49:41.186Z,1379364581.186 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-09-16T20:49:41.192Z,1379364581.192 [MassServo](DEBUG): Initializing EZServoServo.
2013-09-16T20:49:41.198Z,1379364581.198 [MassServo](DEBUG): Initializing MassServo.
2013-09-16T20:49:41.205Z,1379364581.205 [RudderServo](DEBUG): Initializing EZServoServo.
2013-09-16T20:49:41.210Z,1379364581.210 [RudderServo](DEBUG): Initializing RudderServo.
2013-09-16T20:49:41.216Z,1379364581.216 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-09-16T20:49:41.222Z,1379364581.222 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-09-16T20:49:42.211Z,1379364582.211 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout
2013-09-16T20:49:42.212Z,1379364582.212 [ElevatorServo](FAULT): Elevator failed to initialize
2013-09-16T20:49:42.212Z,1379364582.212 [ElevatorServo] Communications Fault, FailCount= 1
2013-09-16T20:49:42.212Z,1379364582.212 [ElevatorServo](ERROR): Communications Fault
2013-09-16T20:49:42.374Z,1379364582.374 [CBIT](ERROR): Communications Fault in component: ElevatorServo
2013-09-16T20:49:42.480Z,1379364582.480 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-16T20:49:42.481Z,1379364582.481 [DVL_micro](INFO): Querying output modes
2013-09-16T20:49:42.481Z,1379364582.481 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-16T20:49:42.492Z,1379364582.492 [DVL_micro](DEBUG): cmdResponse: 01 16
2013-09-16T20:49:42.492Z,1379364582.492 [DVL_micro](INFO): NQ1 output enabled
2013-09-16T20:49:42.492Z,1379364582.492 [DVL_micro](INFO): RSSI output enabled
2013-09-16T20:49:42.493Z,1379364582.493 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-16T20:49:42.504Z,1379364582.504 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-09-16T20:49:42.510Z,1379364582.510 [DVL_micro](INFO): pause:Powering down
2013-09-16T20:49:42.634Z,1379364582.634 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-09-16T20:49:42.634Z,1379364582.634 [ElevatorServo](INFO): Powering down
2013-09-16T20:49:43.527Z,1379364583.527 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-09-16T20:49:43.647Z,1379364583.647 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-09-16T20:49:43.651Z,1379364583.651 [CBIT](INFO): Clearing failed state for component ElevatorServo
2013-09-16T20:49:43.651Z,1379364583.651 [ElevatorServo] No Fault, FailCount= 1
2013-09-16T20:49:45.091Z,1379364585.091 [NAL9602](INFO): Powering up NAL9602
2013-09-16T20:49:55.821Z,1379364595.821 [NAL9602](INFO): NAL9602 initialized
2013-09-16T20:49:55.851Z,1379364595.851 [SBIT](IMPORTANT): Beginning Startup BIT
2013-09-16T20:49:55.862Z,1379364595.862 [CBIT](IMPORTANT): Beginning GF scan
2013-09-16T20:50:00.379Z,1379364600.379 [DAT](INFO): Init failed - response: 
Teledyne Benthos ATM-900 Series
MF Frequency Band
Directional Acoustic Transponder version 8.3.1
Sep 16 2013 21:49:54 

2013-09-16T20:50:00.380Z,1379364600.380 [DAT](FAULT): DAT failed to initialize
2013-09-16T20:50:00.380Z,1379364600.380 [DAT] Communications Fault, FailCount= 1
2013-09-16T20:50:00.380Z,1379364600.380 [DAT](ERROR): Communications Fault
2013-09-16T20:50:00.511Z,1379364600.511 [CBIT](ERROR): Communications Fault in component: DAT
2013-09-16T20:50:00.743Z,1379364600.743 [DAT](INFO): Powering down
2013-09-16T20:50:01.778Z,1379364601.778 [CBIT](INFO): Clearing failed state for component DAT
2013-09-16T20:50:01.778Z,1379364601.778 [DAT] No Fault, FailCount= 1
2013-09-16T20:50:04.117Z,1379364604.117 [DAT](INFO): Powering up
2013-09-16T20:50:04.117Z,1379364604.117 [DAT](DEBUG): Initializing DAT.
2013-09-16T20:50:22.352Z,1379364622.352 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.036061
CHAN 4 (Batt): 0.007461
CHAN 2 (12V): 0.000861
CHAN 1 (5V): 0.000574
CHAN 0 (3.3V): 0.000574
OPEN: 0.000670
Full Scale Calc: 0.392
2013-09-16T20:50:24.316Z,1379364624.316 [DAT](INFO): Powering down
2013-09-16T20:50:42.797Z,1379364642.797 [CommandLine](IMPORTANT): got command ibit
2013-09-16T20:50:42.892Z,1379364642.892 [IBIT](FAULT): Cannot run IBIT while SBIT is in progress.
2013-09-16T20:50:43.291Z,1379364643.291 [IBIT](FAULT): Cannot run IBIT while SBIT is in progress.
2013-09-16T20:50:43.674Z,1379364643.674 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2013-09-16T20:50:43.674Z,1379364643.674 [IBIT](IMPORTANT): buoyancyNeutral: 400.000000 cc
2013-09-16T20:50:43.674Z,1379364643.674 [IBIT](IMPORTANT): massDefault: 0.000000 cm
2013-09-16T20:50:43.675Z,1379364643.675 [IBIT](IMPORTANT): stopDepth: 112.000000 m
2013-09-16T20:50:43.675Z,1379364643.675 [IBIT](IMPORTANT): abortDepth: 130.000000 m
2013-09-16T20:50:43.675Z,1379364643.675 [IBIT](IMPORTANT): IBIT FAILED
2013-09-16T20:50:49.631Z,1379364649.631 [SBIT](IMPORTANT): SBIT PASSED
2013-09-16T20:50:50.030Z,1379364650.030 [MissionManager](IMPORTANT): Started mission Startup
2013-09-16T20:50:50.030Z,1379364650.030 [Startup] Running Loop=1
2013-09-16T20:50:50.030Z,1379364650.030 [Startup](INFO): Aggregate::initialize Startup
2013-09-16T20:50:50.030Z,1379364650.030 [Startup:A.GoToSurface] Running Loop=1
2013-09-16T20:50:50.030Z,1379364650.030 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-16T20:50:50.036Z,1379364650.036 [Startup:StartupSatComms] Running Loop=1
2013-09-16T20:50:50.036Z,1379364650.036 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-09-16T20:50:50.036Z,1379364650.036 [Startup:StartupSatComms:A] Running Loop=1
2013-09-16T20:50:50.426Z,1379364650.426 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-09-16T20:51:01.887Z,1379364661.887 [CommandLine](IMPORTANT): got command ibit
2013-09-16T20:51:02.032Z,1379364662.032 [IBIT](IMPORTANT): Beginning Initiated BIT
2013-09-16T20:51:02.032Z,1379364662.032 [IBIT](IMPORTANT): Beginning control surface checks.

2013-09-16T20:51:02.034Z,1379364662.034 [CBIT](IMPORTANT): Beginning GF scan
2013-09-16T20:51:02.830Z,1379364662.830 [Radio_Freewave](INFO): Powering down
2013-09-16T20:51:03.627Z,1379364663.627 [Radio_Freewave](INFO): Powering up
2013-09-16T20:51:28.994Z,1379364688.994 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.032713
CHAN 4 (Batt): 0.005548
CHAN 2 (12V): 0.000574
CHAN 1 (5V): 0.000670
CHAN 0 (3.3V): 0.000670
OPEN: 0.027357
Full Scale Calc: 0.392
2013-09-16T20:52:13.206Z,1379364733.206 [CommandLine](IMPORTANT): got command run 
2013-09-16T20:52:13.206Z,1379364733.206 [CommandLine](FAULT): Incomplete syntax. Try: help run
2013-09-16T20:52:19.644Z,1379364739.644 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/tank_weight.xml
2013-09-16T20:52:19.644Z,1379364739.644 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_weight.xml
2013-09-16T20:52:19.694Z,1379364739.694 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitHiCC = 0.000955 n/a
2013-09-16T20:52:19.698Z,1379364739.698 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitLoCC = 0.000080 n/a
2013-09-16T20:52:19.700Z,1379364739.700 [tank_weight:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2013-09-16T20:52:19.708Z,1379364739.708 [tank_weight:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2013-09-16T20:52:19.717Z,1379364739.717 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2013-09-16T20:52:19.860Z,1379364739.860 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUS = 0 bool
2013-09-16T20:52:19.863Z,1379364739.863 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2013-09-16T20:52:19.887Z,1379364739.887 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSminPitch = -60.000000 arcdeg
2013-09-16T20:52:19.890Z,1379364739.890 [MissionManager](INFO): DefineArg tank_weight:Science.SampleRSSI = 1 bool
2013-09-16T20:52:19.904Z,1379364739.904 [MissionManager](INFO): DefineArg tank_weight:Science.SampleADCP = 0 bool
2013-09-16T20:52:19.907Z,1379364739.907 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectChlActive = 0 bool
2013-09-16T20:52:19.910Z,1379364739.910 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectNO3Active = 0 bool
2013-09-16T20:52:19.918Z,1379364739.918 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectRSSIActive = 0 bool
2013-09-16T20:52:19.921Z,1379364739.921 [MissionManager](INFO): DefineArg tank_weight:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2013-09-16T20:52:19.924Z,1379364739.924 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrent = 0 bool
2013-09-16T20:52:19.927Z,1379364739.927 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMinDepth = 2.000000 m
2013-09-16T20:52:19.939Z,1379364739.939 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMaxDepth = 5.000000 m
2013-09-16T20:52:19.943Z,1379364739.943 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledAanderaaO2 = 0.000000 n/a
2013-09-16T20:52:19.955Z,1379364739.955 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledNeilBrown = 1.000000 n/a
2013-09-16T20:52:19.986Z,1379364739.986 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledTurbulence_NPS = 0.000000 n/a
2013-09-16T20:52:19.989Z,1379364739.989 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledWetLabsBB2FL = 1.000000 n/a
2013-09-16T20:52:19.993Z,1379364739.993 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledDVL = 1.000000 n/a
2013-09-16T20:52:20.009Z,1379364740.009 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledISUS = 0.000000 n/a
2013-09-16T20:52:20.012Z,1379364740.012 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChl = 0.000000 ug/l
2013-09-16T20:52:20.015Z,1379364740.015 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlDepth = 0.000000 m
2013-09-16T20:52:20.018Z,1379364740.018 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLatitude = nan arcdeg
2013-09-16T20:52:20.022Z,1379364740.022 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLongitude = nan arcdeg
2013-09-16T20:52:20.025Z,1379364740.025 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3 = 0.000000 umol/l
2013-09-16T20:52:20.029Z,1379364740.029 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Depth = 0.000000 m
2013-09-16T20:52:20.032Z,1379364740.032 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Latitude = nan arcdeg
2013-09-16T20:52:20.035Z,1379364740.035 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Longitude = nan arcdeg
2013-09-16T20:52:20.039Z,1379364740.039 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSI = 0.000000 dB
2013-09-16T20:52:20.042Z,1379364740.042 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSIDepth = 0.000000 m
2013-09-16T20:52:20.057Z,1379364740.057 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILatitude = nan arcdeg
2013-09-16T20:52:20.061Z,1379364740.061 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILongitude = nan arcdeg
2013-09-16T20:52:20.116Z,1379364740.116 [tank_weight:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-16T20:52:20.127Z,1379364740.127 [tank_weight:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-16T20:52:20.138Z,1379364740.138 [tank_weight:Science:PeakDetectRSSI:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-16T20:52:20.146Z,1379364740.146 [MissionManager](INFO): RedefineArg tank_weight:Science.SampleISUS = 1 bool
2013-09-16T20:52:20.147Z,1379364740.147 [tank_weight:D:A.SetSpeed](DEBUG): Construct.
2013-09-16T20:52:20.151Z,1379364740.151 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Construct Buoyancy.
2013-09-16T20:52:20.155Z,1379364740.155 [tank_weight:D:BuoyancyLo:B.Pitch](DEBUG): Construct.
2013-09-16T20:52:20.161Z,1379364740.161 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Construct Wait.
2013-09-16T20:52:20.164Z,1379364740.164 [tank_weight:D:BuoyancyHi:A.Buoyancy](DEBUG): Construct Buoyancy.
2013-09-16T20:52:20.183Z,1379364740.183 [tank_weight:D:BuoyancyHi:B.Pitch](DEBUG): Construct.
2013-09-16T20:52:20.199Z,1379364740.199 [tank_weight:D:BuoyancyHi:C.Wait](DEBUG): Construct Wait.
2013-09-16T20:52:20.239Z,1379364740.239 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Trigger="Tethys/Trigger" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="tank_weight">

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

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

    <Timeout Duration="P75M"/>

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

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

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

    <Aggregate>

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

        <Aggregate Id="BuoyancyLo">

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

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

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

        </Aggregate>

        <Aggregate Id="BuoyancyHi">

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

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

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

        </Aggregate>

    </Aggregate>

</Mission>


2013-09-16T20:52:20.246Z,1379364740.246 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/tank_weight.xml
2013-09-16T20:52:38.273Z,1379364758.273 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 950.000000 cubic_centimeter
2013-09-16T20:52:38.275Z,1379364758.275 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2013-09-16T20:52:38.650Z,1379364758.650 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,NAL9602,Onboard,Radio_Freewave,DAT,SCPI,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-09-16T20:52:53.047Z,1379364773.047 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2013-09-16T20:52:53.441Z,1379364773.441 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2013-09-16T20:52:53.844Z,1379364773.844 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2013-09-16T20:52:53.845Z,1379364773.845 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2013-09-16T20:52:53.845Z,1379364773.845 [IBIT](IMPORTANT): Pressure:10.734123 PSI
2013-09-16T20:52:53.845Z,1379364773.845 [IBIT](IMPORTANT): Humidity:6.309653 %
2013-09-16T20:52:54.249Z,1379364774.249 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m
2013-09-16T20:52:54.249Z,1379364774.249 [IBIT](IMPORTANT): buoyancyNeutral: 400.000000 cc
2013-09-16T20:52:54.249Z,1379364774.249 [IBIT](IMPORTANT): massDefault: 0.000000 cm
2013-09-16T20:52:54.250Z,1379364774.250 [IBIT](IMPORTANT): stopDepth: 112.000000 m
2013-09-16T20:52:54.250Z,1379364774.250 [IBIT](IMPORTANT): abortDepth: 130.000000 m
2013-09-16T20:52:54.250Z,1379364774.250 [IBIT](IMPORTANT): IBIT FAILED
2013-09-16T20:52:54.643Z,1379364774.643 [Startup:StartupSatComms:A](INFO): Timed out from 2013-09-16T20:50:50.0Z
2013-09-16T20:52:54.643Z,1379364774.643 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-09-16T20:52:54.643Z,1379364774.643 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-09-16T20:52:54.643Z,1379364774.643 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-09-16T20:52:54.643Z,1379364774.643 [Startup:StartupSatComms:A] Stopped
2013-09-16T20:52:54.644Z,1379364774.644 [Startup:StartupSatComms:B] Running Loop=1
2013-09-16T20:52:55.055Z,1379364775.055 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-09-16T20:53:01.252Z,1379364781.252 [CommandLine](IMPORTANT): got command report periodic 1.000000 
2013-09-16T20:53:01.253Z,1379364781.253 [CommandLine](FAULT): Incomplete syntax. Try: help report
2013-09-16T20:53:19.324Z,1379364799.324 [CommandLine](IMPORTANT): got command report periodic 1.000000 platform_buoyancy_position 
2013-09-16T20:53:19.442Z,1379364799.442 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:20.745Z,1379364800.745 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:21.757Z,1379364801.757 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:22.955Z,1379364802.955 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:24.653Z,1379364804.653 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:25.682Z,1379364805.682 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:26.862Z,1379364806.862 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:28.062Z,1379364808.062 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:29.216Z,1379364809.216 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:30.410Z,1379364810.410 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:31.596Z,1379364811.596 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:33.311Z,1379364813.311 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:34.324Z,1379364814.324 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:35.510Z,1379364815.510 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:36.732Z,1379364816.732 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:37.882Z,1379364817.882 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:39.051Z,1379364819.051 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:40.240Z,1379364820.240 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:41.547Z,1379364821.547 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:42.601Z,1379364822.601 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:43.751Z,1379364823.751 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:44.952Z,1379364824.952 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:45.961Z,1379364825.961 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:46.993Z,1379364826.993 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:48.197Z,1379364828.197 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:48.958Z,1379364828.958 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/tank_weight.xml
2013-09-16T20:53:48.988Z,1379364828.988 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_weight.xml
2013-09-16T20:53:49.038Z,1379364829.038 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitHiCC = 0.000955 n/a
2013-09-16T20:53:49.041Z,1379364829.041 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitLoCC = 0.000080 n/a
2013-09-16T20:53:49.042Z,1379364829.042 [tank_weight:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2013-09-16T20:53:49.047Z,1379364829.047 [tank_weight:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2013-09-16T20:53:49.053Z,1379364829.053 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2013-09-16T20:53:49.182Z,1379364829.182 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUS = 0 bool
2013-09-16T20:53:49.185Z,1379364829.185 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2013-09-16T20:53:49.187Z,1379364829.187 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSminPitch = -60.000000 arcdeg
2013-09-16T20:53:49.189Z,1379364829.189 [MissionManager](INFO): DefineArg tank_weight:Science.SampleRSSI = 1 bool
2013-09-16T20:53:49.191Z,1379364829.191 [MissionManager](INFO): DefineArg tank_weight:Science.SampleADCP = 0 bool
2013-09-16T20:53:49.193Z,1379364829.193 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectChlActive = 0 bool
2013-09-16T20:53:49.195Z,1379364829.195 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectNO3Active = 0 bool
2013-09-16T20:53:49.197Z,1379364829.197 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectRSSIActive = 0 bool
2013-09-16T20:53:49.199Z,1379364829.199 [MissionManager](INFO): DefineArg tank_weight:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2013-09-16T20:53:49.201Z,1379364829.201 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrent = 0 bool
2013-09-16T20:53:49.203Z,1379364829.203 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMinDepth = 2.000000 m
2013-09-16T20:53:49.205Z,1379364829.205 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMaxDepth = 5.000000 m
2013-09-16T20:53:49.208Z,1379364829.208 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledAanderaaO2 = 0.000000 n/a
2013-09-16T20:53:49.210Z,1379364829.210 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledNeilBrown = 1.000000 n/a
2013-09-16T20:53:49.213Z,1379364829.213 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledTurbulence_NPS = 0.000000 n/a
2013-09-16T20:53:49.216Z,1379364829.216 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledWetLabsBB2FL = 1.000000 n/a
2013-09-16T20:53:49.218Z,1379364829.218 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledDVL = 1.000000 n/a
2013-09-16T20:53:49.220Z,1379364829.220 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledISUS = 0.000000 n/a
2013-09-16T20:53:49.223Z,1379364829.223 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChl = 0.000000 ug/l
2013-09-16T20:53:49.225Z,1379364829.225 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlDepth = 0.000000 m
2013-09-16T20:53:49.228Z,1379364829.228 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLatitude = nan arcdeg
2013-09-16T20:53:49.230Z,1379364829.230 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLongitude = nan arcdeg
2013-09-16T20:53:49.233Z,1379364829.233 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3 = 0.000000 umol/l
2013-09-16T20:53:49.235Z,1379364829.235 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Depth = 0.000000 m
2013-09-16T20:53:49.237Z,1379364829.237 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Latitude = nan arcdeg
2013-09-16T20:53:49.241Z,1379364829.241 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Longitude = nan arcdeg
2013-09-16T20:53:49.244Z,1379364829.244 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSI = 0.000000 dB
2013-09-16T20:53:49.246Z,1379364829.246 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSIDepth = 0.000000 m
2013-09-16T20:53:49.248Z,1379364829.248 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILatitude = nan arcdeg
2013-09-16T20:53:49.251Z,1379364829.251 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILongitude = nan arcdeg
2013-09-16T20:53:49.319Z,1379364829.319 [tank_weight:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-16T20:53:49.326Z,1379364829.326 [tank_weight:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-16T20:53:49.335Z,1379364829.335 [tank_weight:Science:PeakDetectRSSI:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2013-09-16T20:53:49.341Z,1379364829.341 [MissionManager](INFO): RedefineArg tank_weight:Science.SampleISUS = 1 bool
2013-09-16T20:53:49.343Z,1379364829.343 [tank_weight:D:A.SetSpeed](DEBUG): Construct.
2013-09-16T20:53:49.346Z,1379364829.346 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Construct Buoyancy.
2013-09-16T20:53:49.348Z,1379364829.348 [tank_weight:D:BuoyancyLo:B.Pitch](DEBUG): Construct.
2013-09-16T20:53:49.353Z,1379364829.353 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Construct Wait.
2013-09-16T20:53:49.355Z,1379364829.355 [tank_weight:D:BuoyancyHi:A.Buoyancy](DEBUG): Construct Buoyancy.
2013-09-16T20:53:49.357Z,1379364829.357 [tank_weight:D:BuoyancyHi:B.Pitch](DEBUG): Construct.
2013-09-16T20:53:49.390Z,1379364829.390 [tank_weight:D:BuoyancyHi:C.Wait](DEBUG): Construct Wait.
2013-09-16T20:53:49.422Z,1379364829.422 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Trigger="Tethys/Trigger" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="tank_weight">

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

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

    <Timeout Duration="P75M"/>

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

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

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

    <Aggregate>

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

        <Aggregate Id="BuoyancyLo">

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

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

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

        </Aggregate>

        <Aggregate Id="BuoyancyHi">

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

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

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

        </Aggregate>

    </Aggregate>

</Mission>


2013-09-16T20:53:49.424Z,1379364829.424 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/tank_weight.xml
2013-09-16T20:53:49.446Z,1379364829.446 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:50.674Z,1379364830.674 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:51.690Z,1379364831.690 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:52.878Z,1379364832.878 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:54.079Z,1379364834.079 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:54.989Z,1379364834.989 [Startup:StartupSatComms:B](INFO): Timed out from 2013-09-16T20:52:54.6Z
2013-09-16T20:53:54.989Z,1379364834.989 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-09-16T20:53:54.989Z,1379364834.989 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-09-16T20:53:54.989Z,1379364834.989 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-09-16T20:53:54.990Z,1379364834.990 [Startup:StartupSatComms:B] Stopped
2013-09-16T20:53:54.990Z,1379364834.990 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-09-16T20:53:54.990Z,1379364834.990 [Startup:StartupSatComms] Stopped
2013-09-16T20:53:54.990Z,1379364834.990 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-09-16T20:53:54.991Z,1379364834.991 [Startup](INFO): Completed Startup
2013-09-16T20:53:54.991Z,1379364834.991 [Startup] Stopped
2013-09-16T20:53:54.991Z,1379364834.991 [Startup](INFO): Aggregate::uninitialize Startup
2013-09-16T20:53:54.991Z,1379364834.991 [Startup:A.GoToSurface] Stopped
2013-09-16T20:53:54.991Z,1379364834.991 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-16T20:53:55.239Z,1379364835.239 [MissionManager](IMPORTANT): Started mission tank_weight
2013-09-16T20:53:55.239Z,1379364835.239 [tank_weight] Running Loop=1
2013-09-16T20:53:55.239Z,1379364835.239 [tank_weight](INFO): Aggregate::initialize tank_weight
2013-09-16T20:53:55.240Z,1379364835.240 [tank_weight:A.AltitudeEnvelope] Running Loop=1
2013-09-16T20:53:55.240Z,1379364835.240 [tank_weight:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2013-09-16T20:53:55.240Z,1379364835.240 [tank_weight:B.DepthEnvelope] Running Loop=1
2013-09-16T20:53:55.240Z,1379364835.240 [tank_weight:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2013-09-16T20:53:55.241Z,1379364835.241 [tank_weight:Science] Running Loop=1
2013-09-16T20:53:55.241Z,1379364835.241 [tank_weight:Science](INFO): Aggregate::initialize tank_weight:Science
2013-09-16T20:53:55.241Z,1379364835.241 [tank_weight:Science:A] Running Loop=1
2013-09-16T20:53:55.241Z,1379364835.241 [tank_weight:Science:B] Running Loop=1
2013-09-16T20:53:55.241Z,1379364835.241 [tank_weight:Science:C] Running Loop=1
2013-09-16T20:53:55.241Z,1379364835.241 [tank_weight:Science:D] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:Science:E] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:Science:F] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:Science:G] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:Science:H] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:Science:I] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:D] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:D](INFO): Aggregate::initialize tank_weight:D
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:D:A.SetSpeed] Running Loop=1
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:D:A.SetSpeed](DEBUG): Initialize.
2013-09-16T20:53:55.242Z,1379364835.242 [tank_weight:D:BuoyancyLo] Running Loop=1
2013-09-16T20:53:55.243Z,1379364835.243 [tank_weight:D:BuoyancyLo](INFO): Aggregate::initialize tank_weight:D:BuoyancyLo
2013-09-16T20:53:55.243Z,1379364835.243 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1
2013-09-16T20:53:55.243Z,1379364835.243 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2013-09-16T20:53:55.243Z,1379364835.243 [tank_weight:D:BuoyancyLo:B.Pitch] Running Loop=1
2013-09-16T20:53:55.243Z,1379364835.243 [tank_weight:D:BuoyancyLo:B.Pitch](DEBUG): Initialize.
2013-09-16T20:53:55.243Z,1379364835.243 [tank_weight:D:BuoyancyLo:C.Wait] Running Loop=1
2013-09-16T20:53:55.244Z,1379364835.244 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Initialize Wait Component.
2013-09-16T20:53:55.249Z,1379364835.249 [tank_weight:D:BuoyancyLo:B.Pitch] Running Loop=1
2013-09-16T20:53:55.254Z,1379364835.254 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1
2013-09-16T20:53:55.259Z,1379364835.259 [tank_weight:D:A.SetSpeed] Running Loop=1
2013-09-16T20:53:55.264Z,1379364835.264 [tank_weight:Science] Running Loop=1
2013-09-16T20:53:55.265Z,1379364835.265 [tank_weight:Science:I] Running Loop=1
2013-09-16T20:53:55.266Z,1379364835.266 [tank_weight:Science:I](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2013-09-16T20:53:55.267Z,1379364835.267 [tank_weight:Science:H] Running Loop=1
2013-09-16T20:53:55.268Z,1379364835.268 [tank_weight:Science:H](DEBUG): Initialize ReadDataComponent to sense DVL_micro.Beam1RSSI
2013-09-16T20:53:55.269Z,1379364835.269 [tank_weight:Science:D] Running Loop=1
2013-09-16T20:53:55.270Z,1379364835.270 [tank_weight:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2013-09-16T20:53:55.270Z,1379364835.270 [tank_weight:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2013-09-16T20:53:55.272Z,1379364835.272 [tank_weight:B.DepthEnvelope] Running Loop=1
2013-09-16T20:53:55.277Z,1379364835.277 [tank_weight:A.AltitudeEnvelope] Running Loop=1
2013-09-16T20:53:55.296Z,1379364835.296 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:55.348Z,1379364835.348 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-09-16T20:53:55.377Z,1379364835.377 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4
2013-09-16T20:53:55.377Z,1379364835.377 [WetLabsBB2FL](INFO): Powering up
2013-09-16T20:53:55.393Z,1379364835.393 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-16T20:53:55.393Z,1379364835.393 [DVL_micro](INFO): resume:Powering up
2013-09-16T20:53:55.393Z,1379364835.393 [DVL_micro](INFO): Cycling power to configure device.
2013-09-16T20:53:56.450Z,1379364836.450 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:56.845Z,1379364836.845 [tank_weight:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2013-09-16T20:53:56.969Z,1379364836.969 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.076900 psu
2013-09-16T20:53:57.179Z,1379364837.179 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.053000 psu
2013-09-16T20:53:57.373Z,1379364837.373 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.063200 psu
2013-09-16T20:53:57.399Z,1379364837.399 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-16T20:53:57.399Z,1379364837.399 [DVL_micro](INFO): Querying output modes
2013-09-16T20:53:57.400Z,1379364837.400 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-16T20:53:57.411Z,1379364837.411 [DVL_micro](DEBUG): cmdResponse: 01 16
2013-09-16T20:53:57.411Z,1379364837.411 [DVL_micro](INFO): NQ1 output enabled
2013-09-16T20:53:57.411Z,1379364837.411 [DVL_micro](INFO): RSSI output enabled
2013-09-16T20:53:57.412Z,1379364837.412 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-16T20:53:57.423Z,1379364837.423 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-09-16T20:53:57.560Z,1379364837.560 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40
2013-09-16T20:53:57.576Z,1379364837.576 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.001500 psu
2013-09-16T20:53:57.614Z,1379364837.614 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60
2013-09-16T20:53:57.660Z,1379364837.660 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:57.664Z,1379364837.664 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48
2013-09-16T20:53:57.724Z,1379364837.724 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2013-09-16T20:53:57.780Z,1379364837.780 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.020400 psu
2013-09-16T20:53:57.981Z,1379364837.981 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.032200 psu
2013-09-16T20:53:57.996Z,1379364837.996 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56
2013-09-16T20:53:58.108Z,1379364838.108 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92
2013-09-16T20:53:58.185Z,1379364838.185 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.006800 psu
2013-09-16T20:53:58.221Z,1379364838.221 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=256
2013-09-16T20:53:58.321Z,1379364838.321 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2013-09-16T20:53:58.393Z,1379364838.393 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.018600 psu
2013-09-16T20:53:58.442Z,1379364838.442 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40
2013-09-16T20:53:58.501Z,1379364838.501 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60
2013-09-16T20:53:58.550Z,1379364838.550 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=17
2013-09-16T20:53:58.594Z,1379364838.594 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.025400 psu
2013-09-16T20:53:58.622Z,1379364838.622 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2013-09-16T20:53:58.794Z,1379364838.794 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.012800 psu
2013-09-16T20:53:58.879Z,1379364838.879 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:53:58.894Z,1379364838.894 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120
2013-09-16T20:53:58.998Z,1379364838.998 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.011100 psu
2013-09-16T20:53:58.000Z,1379364839.000 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=124
2013-09-16T20:53:59.094Z,1379364839.094 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32
2013-09-16T20:53:59.194Z,1379364839.194 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2013-09-16T20:53:59.211Z,1379364839.211 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010400 psu
2013-09-16T20:53:59.423Z,1379364839.423 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.000700 psu
2013-09-16T20:53:59.543Z,1379364839.543 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24
2013-09-16T20:53:59.620Z,1379364839.620 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.014700 psu
2013-09-16T20:53:59.691Z,1379364839.691 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=92
2013-09-16T20:53:59.819Z,1379364839.819 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.004700 psu
2013-09-16T20:53:59.831Z,1379364839.831 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0
2013-09-16T20:53:59.983Z,1379364839.983 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4
2013-09-16T20:54:00.020Z,1379364840.020 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.006700 psu
2013-09-16T20:54:00.078Z,1379364840.078 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:00.224Z,1379364840.224 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.008600 psu
2013-09-16T20:54:00.304Z,1379364840.304 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=124
2013-09-16T20:54:00.425Z,1379364840.425 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=164
2013-09-16T20:54:00.437Z,1379364840.437 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.047500 psu
2013-09-16T20:54:00.537Z,1379364840.537 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=108
2013-09-16T20:54:00.633Z,1379364840.633 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.009800 psu
2013-09-16T20:54:00.652Z,1379364840.652 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4
2013-09-16T20:54:00.837Z,1379364840.837 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.008100 psu
2013-09-16T20:54:01.036Z,1379364841.036 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010700 psu
2013-09-16T20:54:01.181Z,1379364841.181 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=124
2013-09-16T20:54:01.250Z,1379364841.250 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.009600 psu
2013-09-16T20:54:01.267Z,1379364841.267 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:01.419Z,1379364841.419 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=164
2013-09-16T20:54:01.446Z,1379364841.446 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.001000 psu
2013-09-16T20:54:01.646Z,1379364841.646 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=44
2013-09-16T20:54:01.658Z,1379364841.658 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.011400 psu
2013-09-16T20:54:01.858Z,1379364841.858 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010000 psu
2013-09-16T20:54:01.890Z,1379364841.890 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4
2013-09-16T20:54:02.063Z,1379364842.063 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.016200 psu
2013-09-16T20:54:02.263Z,1379364842.263 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.008000 psu
2013-09-16T20:54:02.469Z,1379364842.469 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:02.472Z,1379364842.472 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.011600 psu
2013-09-16T20:54:02.772Z,1379364842.772 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.001200 psu
2013-09-16T20:54:02.800Z,1379364842.800 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28
2013-09-16T20:54:02.973Z,1379364842.973 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010400 psu
2013-09-16T20:54:03.181Z,1379364843.181 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.002200 psu
2013-09-16T20:54:03.276Z,1379364843.276 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=36
2013-09-16T20:54:03.385Z,1379364843.385 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.011100 psu
2013-09-16T20:54:03.590Z,1379364843.590 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.009100 psu
2013-09-16T20:54:03.657Z,1379364843.657 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:03.750Z,1379364843.750 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=12
2013-09-16T20:54:03.797Z,1379364843.797 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.001100 psu
2013-09-16T20:54:03.998Z,1379364843.998 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.007100 psu
2013-09-16T20:54:04.202Z,1379364844.202 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.008000 psu
2013-09-16T20:54:04.230Z,1379364844.230 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4
2013-09-16T20:54:04.407Z,1379364844.407 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.018800 psu
2013-09-16T20:54:04.607Z,1379364844.607 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.013000 psu
2013-09-16T20:54:04.819Z,1379364844.819 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.017000 psu
2013-09-16T20:54:04.858Z,1379364844.858 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:05.031Z,1379364845.031 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.014200 psu
2013-09-16T20:54:05.119Z,1379364845.119 [DVL_micro](DEBUG): NQ1
2013-09-16T20:54:05.236Z,1379364845.236 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.011000 psu
2013-09-16T20:54:05.432Z,1379364845.432 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.004800 psu
2013-09-16T20:54:05.645Z,1379364845.645 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.026900 psu
2013-09-16T20:54:05.849Z,1379364845.849 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.015600 psu
2013-09-16T20:54:05.961Z,1379364845.961 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=2
2013-09-16T20:54:06.055Z,1379364846.055 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:06.062Z,1379364846.062 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.001200 psu
2013-09-16T20:54:06.258Z,1379364846.258 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.001700 psu
2013-09-16T20:54:06.463Z,1379364846.463 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.014100 psu
2013-09-16T20:54:06.671Z,1379364846.671 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.027300 psu
2013-09-16T20:54:06.810Z,1379364846.810 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=74
2013-09-16T20:54:06.975Z,1379364846.975 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.087000 psu
2013-09-16T20:54:07.179Z,1379364847.179 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.008000 psu
2013-09-16T20:54:07.262Z,1379364847.262 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:07.375Z,1379364847.375 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.003700 psu
2013-09-16T20:54:07.579Z,1379364847.579 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.007400 psu
2013-09-16T20:54:07.636Z,1379364847.636 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=19
2013-09-16T20:54:07.788Z,1379364847.788 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.025700 psu
2013-09-16T20:54:07.992Z,1379364847.992 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.005100 psu
2013-09-16T20:54:08.196Z,1379364848.196 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.002100 psu
2013-09-16T20:54:08.405Z,1379364848.405 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010400 psu
2013-09-16T20:54:08.455Z,1379364848.455 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:08.485Z,1379364848.485 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4
2013-09-16T20:54:08.621Z,1379364848.621 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.009700 psu
2013-09-16T20:54:08.813Z,1379364848.813 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.030300 psu
2013-09-16T20:54:08.837Z,1379364848.837 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=104
2013-09-16T20:54:08.885Z,1379364848.885 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=62
2013-09-16T20:54:08.938Z,1379364848.938 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=18
2013-09-16T20:54:08.998Z,1379364848.998 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2013-09-16T20:54:09.014Z,1379364849.014 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.005500 psu
2013-09-16T20:54:09.218Z,1379364849.218 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.002000 psu
2013-09-16T20:54:09.270Z,1379364849.270 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24
2013-09-16T20:54:09.378Z,1379364849.378 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28
2013-09-16T20:54:09.423Z,1379364849.423 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.011300 psu
2013-09-16T20:54:09.482Z,1379364849.482 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=96
2013-09-16T20:54:09.591Z,1379364849.591 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2013-09-16T20:54:09.639Z,1379364849.639 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.015000 psu
2013-09-16T20:54:09.682Z,1379364849.682 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:09.731Z,1379364849.731 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=104
2013-09-16T20:54:09.771Z,1379364849.771 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28
2013-09-16T20:54:09.827Z,1379364849.827 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=80
2013-09-16T20:54:09.840Z,1379364849.840 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.029500 psu
2013-09-16T20:54:09.887Z,1379364849.887 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4
2013-09-16T20:54:10.047Z,1379364850.047 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.002900 psu
2013-09-16T20:54:10.171Z,1379364850.171 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=152
2013-09-16T20:54:10.244Z,1379364850.244 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.008200 psu
2013-09-16T20:54:10.272Z,1379364850.272 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92
2013-09-16T20:54:10.367Z,1379364850.367 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32
2013-09-16T20:54:10.452Z,1379364850.452 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.027200 psu
2013-09-16T20:54:10.468Z,1379364850.468 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4
2013-09-16T20:54:10.658Z,1379364850.658 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010700 psu
2013-09-16T20:54:10.817Z,1379364850.817 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56
2013-09-16T20:54:10.854Z,1379364850.854 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:10.865Z,1379364850.865 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.083600 psu
2013-09-16T20:54:10.960Z,1379364850.960 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28
2013-09-16T20:54:11.121Z,1379364851.121 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=128
2013-09-16T20:54:11.169Z,1379364851.169 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.025400 psu
2013-09-16T20:54:11.249Z,1379364851.249 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4
2013-09-16T20:54:11.377Z,1379364851.377 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.021200 psu
2013-09-16T20:54:11.582Z,1379364851.582 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=124
2013-09-16T20:54:11.585Z,1379364851.585 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.023400 psu
2013-09-16T20:54:11.690Z,1379364851.690 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4
2013-09-16T20:54:11.790Z,1379364851.790 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.028200 psu
2013-09-16T20:54:11.819Z,1379364851.819 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=204
2013-09-16T20:54:11.930Z,1379364851.930 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4
2013-09-16T20:54:11.998Z,1379364851.998 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.039500 psu
2013-09-16T20:54:12.080Z,1379364852.080 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:12.220Z,1379364852.220 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.023300 psu
2013-09-16T20:54:12.415Z,1379364852.415 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.007100 psu
2013-09-16T20:54:12.447Z,1379364852.447 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=60
2013-09-16T20:54:12.627Z,1379364852.627 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010400 psu
2013-09-16T20:54:12.683Z,1379364852.683 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4
2013-09-16T20:54:12.832Z,1379364852.832 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.033200 psu
2013-09-16T20:54:12.932Z,1379364852.932 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=204
2013-09-16T20:54:13.032Z,1379364853.032 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.010400 psu
2013-09-16T20:54:13.156Z,1379364853.156 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4
2013-09-16T20:54:13.229Z,1379364853.229 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.001300 psu
2013-09-16T20:54:13.271Z,1379364853.271 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:13.437Z,1379364853.437 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010500 psu
2013-09-16T20:54:13.649Z,1379364853.649 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.008600 psu
2013-09-16T20:54:13.845Z,1379364853.845 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.013300 psu
2013-09-16T20:54:14.050Z,1379364854.050 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.033800 psu
2013-09-16T20:54:14.085Z,1379364854.085 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=92
2013-09-16T20:54:14.258Z,1379364854.258 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010500 psu
2013-09-16T20:54:14.462Z,1379364854.462 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:14.470Z,1379364854.470 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.012700 psu
2013-09-16T20:54:14.558Z,1379364854.558 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=68
2013-09-16T20:54:14.671Z,1379364854.671 [CTD_NeilBrown](ERROR): Salinity reading out of range: -0.001200 psu
2013-09-16T20:54:14.967Z,1379364854.967 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.003000 psu
2013-09-16T20:54:15.023Z,1379364855.023 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=12
2013-09-16T20:54:15.172Z,1379364855.172 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.012700 psu
2013-09-16T20:54:15.384Z,1379364855.384 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.033000 psu
2013-09-16T20:54:15.500Z,1379364855.500 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4
2013-09-16T20:54:15.531Z,1379364855.531 [CommandLine](IMPORTANT): got command quit
2013-09-16T20:54:15.593Z,1379364855.593 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.001700 psu
2013-09-16T20:54:15.663Z,1379364855.663 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:15.797Z,1379364855.797 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.027500 psu
2013-09-16T20:54:16.009Z,1379364856.009 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.018700 psu
2013-09-16T20:54:16.221Z,1379364856.221 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.016900 psu
2013-09-16T20:54:16.393Z,1379364856.393 [DVL_micro](DEBUG): NQ1
2013-09-16T20:54:16.425Z,1379364856.425 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.009500 psu
2013-09-16T20:54:16.601Z,1379364856.601 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2013-09-16T20:54:16.601Z,1379364856.601 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2013-09-16T20:54:16.627Z,1379364856.627 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.010500 psu
2013-09-16T20:54:16.741Z,1379364856.741 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2013-09-16T20:54:16.826Z,1379364856.826 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.012900 psu
2013-09-16T20:54:16.860Z,1379364856.860 [tank_weight] Stopped
2013-09-16T20:54:16.860Z,1379364856.860 [tank_weight](INFO): Aggregate::uninitialize tank_weight
2013-09-16T20:54:16.860Z,1379364856.860 [tank_weight:A.AltitudeEnvelope] Stopped
2013-09-16T20:54:16.860Z,1379364856.860 [tank_weight:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2013-09-16T20:54:16.860Z,1379364856.860 [tank_weight:B.DepthEnvelope] Stopped
2013-09-16T20:54:16.860Z,1379364856.860 [tank_weight:B.DepthEnvelope](DEBUG): Uninitialize.
2013-09-16T20:54:16.860Z,1379364856.860 [tank_weight:Science] Stopped
2013-09-16T20:54:16.861Z,1379364856.861 [tank_weight:Science](INFO): Aggregate::uninitialize tank_weight:Science
2013-09-16T20:54:16.861Z,1379364856.861 [tank_weight:Science:A] Stopped
2013-09-16T20:54:16.861Z,1379364856.861 [tank_weight:Science:B] Stopped
2013-09-16T20:54:16.865Z,1379364856.865 [tank_weight:Science:C] Stopped
2013-09-16T20:54:16.865Z,1379364856.865 [tank_weight:Science:D] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:Science:E] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:Science:F] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:Science:G] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:Science:H] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:Science:I] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D](INFO): Aggregate::uninitialize tank_weight:D
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D:A.SetSpeed] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D:A.SetSpeed](DEBUG): Uninitialize.
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D:BuoyancyLo] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D:BuoyancyLo](INFO): Aggregate::uninitialize tank_weight:D:BuoyancyLo
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D:BuoyancyLo:A.Buoyancy] Stopped
2013-09-16T20:54:16.866Z,1379364856.866 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2013-09-16T20:54:16.867Z,1379364856.867 [tank_weight:D:BuoyancyLo:B.Pitch] Stopped
2013-09-16T20:54:16.867Z,1379364856.867 [tank_weight:D:BuoyancyLo:C.Wait] Stopped
2013-09-16T20:54:16.867Z,1379364856.867 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Uninitialize Wait Component.
2013-09-16T20:54:16.891Z,1379364856.891 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:16.893Z,1379364856.893 [WetLabsBB2FL](INFO): Powering down
2013-09-16T20:54:16.905Z,1379364856.905 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2013-09-16T20:54:17.034Z,1379364857.034 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.017400 psu
2013-09-16T20:54:17.154Z,1379364857.154 [CTD_NeilBrown](INFO): Powering down
2013-09-16T20:54:17.166Z,1379364857.166 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2013-09-16T20:54:17.237Z,1379364857.237 [MissionManager](IMPORTANT): Started mission Default
2013-09-16T20:54:17.237Z,1379364857.237 [Default] Running Loop=1
2013-09-16T20:54:17.238Z,1379364857.238 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=33
2013-09-16T20:54:17.239Z,1379364857.239 [DVL_micro](INFO): uninitialize:Powering down
2013-09-16T20:54:17.240Z,1379364857.240 [Default](INFO): Aggregate::initialize Default
2013-09-16T20:54:17.240Z,1379364857.240 [Default:D.SetSpeed] Running Loop=1
2013-09-16T20:54:17.240Z,1379364857.240 [Default:D.SetSpeed](DEBUG): Initialize.
2013-09-16T20:54:17.240Z,1379364857.240 [Default:E.GoToSurface] Running Loop=1
2013-09-16T20:54:17.240Z,1379364857.240 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-16T20:54:17.240Z,1379364857.240 [Default:Iridium] Running Loop=1
2013-09-16T20:54:17.240Z,1379364857.240 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-09-16T20:54:17.240Z,1379364857.240 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-09-16T20:54:17.240Z,1379364857.240 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-09-16T20:54:17.241Z,1379364857.241 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-09-16T20:54:17.241Z,1379364857.241 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-16T20:54:17.241Z,1379364857.241 [Default:E.GoToSurface] Running Loop=1
2013-09-16T20:54:17.247Z,1379364857.247 [Default:D.SetSpeed] Running Loop=1
2013-09-16T20:54:17.252Z,1379364857.252 [Default:CallIridium] Running Loop=1
2013-09-16T20:54:17.253Z,1379364857.253 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-09-16T20:54:17.253Z,1379364857.253 [Default:CallIridium:A] Running Loop=1
2013-09-16T20:54:17.255Z,1379364857.255 [Default:CallIridium:A] Stopped
2013-09-16T20:54:17.255Z,1379364857.255 [Default:CallIridium:B] Running Loop=1
2013-09-16T20:54:17.255Z,1379364857.255 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-09-16T20:54:17.260Z,1379364857.260 [Default:Iridium:B.GoToSurface] Stopped
2013-09-16T20:54:17.261Z,1379364857.261 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-16T20:54:17.261Z,1379364857.261 [Default:Iridium:Read_Iridium] Running Loop=1
2013-09-16T20:54:17.261Z,1379364857.261 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-09-16T20:54:17.266Z,1379364857.266 [Default:GPS] Running Loop=1
2013-09-16T20:54:17.266Z,1379364857.266 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-09-16T20:54:17.266Z,1379364857.266 [Default:GPS:A.SetSpeed] Running Loop=1
2013-09-16T20:54:17.266Z,1379364857.266 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-09-16T20:54:17.266Z,1379364857.266 [Default:GPS:B.GoToSurface] Running Loop=1
2013-09-16T20:54:17.266Z,1379364857.266 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-16T20:54:17.272Z,1379364857.272 [Default:GPS:B.GoToSurface] Stopped
2013-09-16T20:54:17.272Z,1379364857.272 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-16T20:54:17.272Z,1379364857.272 [Default:GPS:Read_GPS] Running Loop=1
2013-09-16T20:54:17.272Z,1379364857.272 [Default:GPS:A.SetSpeed] Running Loop=1
2013-09-16T20:54:17.631Z,1379364857.631 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-09-16T20:54:17.635Z,1379364857.635 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-09-16T20:54:17.643Z,1379364857.643 [DVL_micro](INFO): uninitialize:Powering down
2013-09-16T20:54:17.646Z,1379364857.646 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2013-09-16T20:54:17.947Z,1379364857.947 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2013-09-16T20:54:17.964Z,1379364857.964 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2013-09-16T20:54:18.012Z,1379364858.012 [Reporter](INFO): platform_buoyancy_position no_value
2013-09-16T20:54:18.024Z,1379364858.024 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2013-09-16T20:54:18.025Z,1379364858.025 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2013-09-16T20:54:18.203Z,1379364858.203 [controlThread](DEBUG): Uninitializing ControlThread
2013-09-16T20:54:18.204Z,1379364858.204 [AHRS_sp3003D](INFO): Powering down
2013-09-16T20:54:18.292Z,1379364858.292 [NAL9602](INFO): Powering down
2013-09-16T20:54:18.293Z,1379364858.293 [DAT](INFO): Powering down
2013-09-16T20:54:18.295Z,1379364858.295 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-09-16T20:54:18.295Z,1379364858.295 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2013-09-16T20:54:18.296Z,1379364858.296 [Default] Stopped
2013-09-16T20:54:18.297Z,1379364858.297 [Default](INFO): Aggregate::uninitialize Default
2013-09-16T20:54:18.297Z,1379364858.297 [Default:GPS] Stopped
2013-09-16T20:54:18.297Z,1379364858.297 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-09-16T20:54:18.297Z,1379364858.297 [Default:GPS:A.SetSpeed] Stopped
2013-09-16T20:54:18.297Z,1379364858.297 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-09-16T20:54:18.297Z,1379364858.297 [Default:GPS:Read_GPS] Stopped
2013-09-16T20:54:18.297Z,1379364858.297 [Default:Iridium] Stopped
2013-09-16T20:54:18.297Z,1379364858.297 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-09-16T20:54:18.297Z,1379364858.297 [Default:Iridium:A.SetSpeed] Stopped
2013-09-16T20:54:18.297Z,1379364858.297 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-09-16T20:54:18.297Z,1379364858.297 [Default:Iridium:Read_Iridium] Stopped
2013-09-16T20:54:18.297Z,1379364858.297 [Default:CallIridium] Stopped
2013-09-16T20:54:18.298Z,1379364858.298 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-09-16T20:54:18.298Z,1379364858.298 [Default:CallIridium:B] Stopped
2013-09-16T20:54:18.298Z,1379364858.298 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-09-16T20:54:18.298Z,1379364858.298 [Default:D.SetSpeed] Stopped
2013-09-16T20:54:18.298Z,1379364858.298 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-09-16T20:54:18.298Z,1379364858.298 [Default:E.GoToSurface] Stopped
2013-09-16T20:54:18.298Z,1379364858.298 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-16T20:54:18.302Z,1379364858.302 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2013-09-16T20:54:18.302Z,1379364858.302 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2013-09-16T20:54:18.303Z,1379364858.303 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2013-09-16T20:54:18.303Z,1379364858.303 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2013-09-16T20:54:18.304Z,1379364858.304 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-09-16T20:54:18.304Z,1379364858.304 [ElevatorServo](INFO): Powering down
2013-09-16T20:54:18.305Z,1379364858.305 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-09-16T20:54:18.305Z,1379364858.305 [MassServo](INFO): Powering down
2013-09-16T20:54:18.306Z,1379364858.306 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-09-16T20:54:18.306Z,1379364858.306 [RudderServo](INFO): Powering down
2013-09-16T20:54:18.307Z,1379364858.307 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-09-16T20:54:18.307Z,1379364858.307 [ThrusterServo](INFO): Powering down
2013-09-16T20:54:18.308Z,1379364858.308 [SBIT](DEBUG): Uninitialize SBIT Component.
2013-09-16T20:54:18.308Z,1379364858.308 [IBIT](DEBUG): Uninitialize IBIT Component.
2013-09-16T20:54:18.308Z,1379364858.308 [CBIT](DEBUG): Uninitialize CBIT Component.