2011-11-12T20:14:06.86130Z,1321128846.8613 [Supervisor](DEBUG): Initializing supervisor.
2011-11-12T20:14:06.86370Z,1321128846.8637 [SyncHandler](DEBUG): Created PCaller Thread at 1077007584
2011-11-12T20:14:06.86430Z,1321128846.8643 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2011-11-12T20:14:06.86530Z,1321128846.8653 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 1077073120
2011-11-12T20:14:06.86620Z,1321128846.8662 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2011-11-12T20:14:06.87830Z,1321128846.8783 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2011-11-12T20:14:06.87930Z,1321128846.8793 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 1077138656
2011-11-12T20:14:06.88020Z,1321128846.8802 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2011-11-12T20:14:06.88060Z,1321128846.8806 [Supervisor](INFO): Looking for Config files in directory: Config/
2011-11-12T20:14:06.88180Z,1321128846.8818 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2011-11-12T20:14:07.14750Z,1321128847.1475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2011-11-12T20:14:07.14800Z,1321128847.148 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2011-11-12T20:14:07.32140Z,1321128847.3214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2011-11-12T20:14:07.32190Z,1321128847.3219 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2011-11-12T20:14:07.40930Z,1321128847.4093 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2011-11-12T20:14:07.40980Z,1321128847.4098 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2011-11-12T20:14:07.60940Z,1321128847.6094 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2011-11-12T20:14:07.61000Z,1321128847.61 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2011-11-12T20:14:07.73390Z,1321128847.7339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2011-11-12T20:14:07.73440Z,1321128847.7344 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2011-11-12T20:14:07.95660Z,1321128847.9566 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2011-11-12T20:14:07.95720Z,1321128847.9572 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2011-11-12T20:14:08.09740Z,1321128848.0974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2011-11-12T20:14:08.09800Z,1321128848.098 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2011-11-12T20:14:08.34430Z,1321128848.3443 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2011-11-12T20:14:08.34480Z,1321128848.3448 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2011-11-12T20:14:08.44610Z,1321128848.4461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2011-11-12T20:14:08.44660Z,1321128848.4466 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2011-11-12T20:14:08.83550Z,1321128848.8355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2011-11-12T20:14:08.83610Z,1321128848.8361 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2011-11-12T20:14:08.96780Z,1321128848.9678 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2011-11-12T20:14:08.96850Z,1321128848.9685 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2011-11-12T20:14:09.05420Z,1321128849.0542 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-tethys/
2011-11-12T20:14:09.05510Z,1321128849.0551 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/vehicle.cfg
2011-11-12T20:14:09.15740Z,1321128849.1574 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Sensor.cfg
2011-11-12T20:14:09.27530Z,1321128849.2753 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/BIT.cfg
2011-11-12T20:14:09.37240Z,1321128849.3724 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Servo.cfg
2011-11-12T20:14:09.46830Z,1321128849.4683 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Science.cfg
2011-11-12T20:14:09.56010Z,1321128849.5601 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/workSite.cfg
2011-11-12T20:14:09.64690Z,1321128849.6469 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Simulator.cfg
2011-11-12T20:14:09.73150Z,1321128849.7315 [Supervisor](INFO): Opening Config file at: Config/lrauv-tethys/Derivation.cfg
2011-11-12T20:14:09.83890Z,1321128849.8389 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2011-11-12T20:14:09.91870Z,1321128849.9187 [InternalSim] Loaded
2011-11-12T20:14:09.91900Z,1321128849.919 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2011-11-12T20:14:09.91980Z,1321128849.9198 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2011-11-12T20:14:09.92040Z,1321128849.9204 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2011-11-12T20:14:09.93280Z,1321128849.9328 [SBIT](DEBUG): Construct Startup Built In Test.
2011-11-12T20:14:09.95930Z,1321128849.9593 [SBIT] Loaded
2011-11-12T20:14:09.95950Z,1321128849.9595 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2011-11-12T20:14:09.96040Z,1321128849.9604 [IBIT](DEBUG): Construct Initiated Built In Test.
2011-11-12T20:14:09.98250Z,1321128849.9825 [IBIT] Loaded
2011-11-12T20:14:09.98270Z,1321128849.9827 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2011-11-12T20:14:09.98920Z,1321128849.9892 [CBIT](DEBUG): Construct CBIT Built In Test.
2011-11-12T20:14:10.04080Z,1321128850.0408 [CBIT] Loaded
2011-11-12T20:14:10.04110Z,1321128850.0411 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2011-11-12T20:14:10.04150Z,1321128850.0415 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2011-11-12T20:14:10.04200Z,1321128850.042 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2011-11-12T20:14:10.13620Z,1321128850.1362 [BuoyancyServo] Loaded
2011-11-12T20:14:10.13650Z,1321128850.1365 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2011-11-12T20:14:10.14310Z,1321128850.1431 [ElevatorServo] Loaded
2011-11-12T20:14:10.14340Z,1321128850.1434 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2011-11-12T20:14:10.14980Z,1321128850.1498 [MassServo] Loaded
2011-11-12T20:14:10.15000Z,1321128850.15 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2011-11-12T20:14:10.15640Z,1321128850.1564 [RudderServo] Loaded
2011-11-12T20:14:10.15670Z,1321128850.1567 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2011-11-12T20:14:10.16320Z,1321128850.1632 [ThrusterServo] Loaded
2011-11-12T20:14:10.16340Z,1321128850.1634 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2011-11-12T20:14:10.16380Z,1321128850.1638 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2011-11-12T20:14:10.16440Z,1321128850.1644 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2011-11-12T20:14:10.18480Z,1321128850.1848 [Bathymetry] Loaded
2011-11-12T20:14:10.18500Z,1321128850.185 [ComponentRegistry](DEBUG): SyncComponent "Bathymetry" handled in the control thread.
2011-11-12T20:14:10.19040Z,1321128850.1904 [DepthRateCalculator] Loaded
2011-11-12T20:14:10.19060Z,1321128850.1906 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2011-11-12T20:14:10.19600Z,1321128850.196 [PitchRateCalculator] Loaded
2011-11-12T20:14:10.19620Z,1321128850.1962 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2011-11-12T20:14:10.20150Z,1321128850.2015 [SpeedCalculator] Loaded
2011-11-12T20:14:10.20180Z,1321128850.2018 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2011-11-12T20:14:10.21510Z,1321128850.2151 [TempGradientCalculator] Loaded
2011-11-12T20:14:10.21540Z,1321128850.2154 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2011-11-12T20:14:10.22080Z,1321128850.2208 [YawRateCalculator] Loaded
2011-11-12T20:14:10.22100Z,1321128850.221 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2011-11-12T20:14:10.24930Z,1321128850.2493 [Navigation] Loaded
2011-11-12T20:14:10.24960Z,1321128850.2496 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2011-11-12T20:14:10.25000Z,1321128850.25 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2011-11-12T20:14:10.25050Z,1321128850.2505 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2011-11-12T20:14:10.29810Z,1321128850.2981 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2011-11-12T20:14:10.29870Z,1321128850.2987 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2011-11-12T20:14:10.30810Z,1321128850.3081 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2011-11-12T20:14:10.30870Z,1321128850.3087 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2011-11-12T20:14:10.32080Z,1321128850.3208 [VerticalControl](DEBUG): Construct VerticalControl.
2011-11-12T20:14:10.51250Z,1321128850.5125 [VerticalControl] Loaded
2011-11-12T20:14:10.51280Z,1321128850.5128 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2011-11-12T20:14:10.51370Z,1321128850.5137 [HorizontalControl](DEBUG): Construct HorizontalControl.
2011-11-12T20:14:10.56290Z,1321128850.5629 [HorizontalControl] Loaded
2011-11-12T20:14:10.56320Z,1321128850.5632 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2011-11-12T20:14:10.56410Z,1321128850.5641 [SpeedControl](DEBUG): Construct SpeedControl.
2011-11-12T20:14:10.56570Z,1321128850.5657 [SpeedControl] Loaded
2011-11-12T20:14:10.56600Z,1321128850.566 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2011-11-12T20:14:10.56680Z,1321128850.5668 [LoopControl](DEBUG): Construct LoopControl.
2011-11-12T20:14:10.56760Z,1321128850.5676 [LoopControl] Loaded
2011-11-12T20:14:10.56780Z,1321128850.5678 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2011-11-12T20:14:10.56820Z,1321128850.5682 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2011-11-12T20:14:10.56880Z,1321128850.5688 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2011-11-12T20:14:10.57400Z,1321128850.574 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2011-11-12T20:14:10.57850Z,1321128850.5785 [AsyncPiEstimator] Loaded
2011-11-12T20:14:10.57870Z,1321128850.5787 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2011-11-12T20:14:10.58000Z,1321128850.58 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 1078400224
2011-11-12T20:14:10.58060Z,1321128850.5806 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2011-11-12T20:14:10.58120Z,1321128850.5812 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2011-11-12T20:14:10.66210Z,1321128850.6621 [AHRS_sp3003D] Loaded
2011-11-12T20:14:10.66240Z,1321128850.6624 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2011-11-12T20:14:10.70010Z,1321128850.7001 [AHRS_3DMGX3] Loaded
2011-11-12T20:14:10.70040Z,1321128850.7004 [ComponentRegistry](DEBUG): SyncComponent "AHRS_3DMGX3" handled in the control thread.
2011-11-12T20:14:10.98010Z,1321128850.9801 [Batt_Ocean_Server] Loaded
2011-11-12T20:14:10.98040Z,1321128850.9804 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2011-11-12T20:14:10.99170Z,1321128850.9917 [Depth_Keller] Loaded
2011-11-12T20:14:10.99200Z,1321128850.992 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2011-11-12T20:14:10.99740Z,1321128850.9974 [DropWeight] Loaded
2011-11-12T20:14:10.99770Z,1321128850.9977 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2011-11-12T20:14:11.08390Z,1321128851.0839 [DVL_micro] Loaded
2011-11-12T20:14:11.08420Z,1321128851.0842 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2011-11-12T20:14:11.15930Z,1321128851.1593 [NAL9601] Loaded
2011-11-12T20:14:11.15960Z,1321128851.1596 [ComponentRegistry](DEBUG): SyncComponent "NAL9601" handled in the control thread.
2011-11-12T20:14:11.20580Z,1321128851.2058 [Onboard] Loaded
2011-11-12T20:14:11.20610Z,1321128851.2061 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2011-11-12T20:14:11.21210Z,1321128851.2121 [Radio_Freewave] Loaded
2011-11-12T20:14:11.21240Z,1321128851.2124 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2011-11-12T20:14:11.23050Z,1321128851.2305 [DAT] Loaded
2011-11-12T20:14:11.23080Z,1321128851.2308 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2011-11-12T20:14:11.23120Z,1321128851.2312 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2011-11-12T20:14:11.23180Z,1321128851.2318 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2011-11-12T20:14:11.26980Z,1321128851.2698 [WetLabsBB2FL] Loaded
2011-11-12T20:14:11.27010Z,1321128851.2701 [ComponentRegistry](DEBUG): SyncComponent "WetLabsBB2FL" handled in the control thread.
2011-11-12T20:14:11.27120Z,1321128851.2712 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2011-11-12T20:14:11.27330Z,1321128851.2733 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2011-11-12T20:14:11.27400Z,1321128851.274 [ComponentRegistry](DEBUG): SyncComponent "Maintainer" handled in the control thread.
2011-11-12T20:14:11.27470Z,1321128851.2747 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2011-11-12T20:14:11.27490Z,1321128851.2749 [Supervisor](DEBUG): Running supervisor.
2011-11-12T20:14:11.27790Z,1321128851.2779 [controlThread](DEBUG): Initializing ControlThread
2011-11-12T20:14:11.27880Z,1321128851.2788 [InternalSim](DEBUG):  InternalSim initializing...
2011-11-12T20:14:11.31090Z,1321128851.3109 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2011-11-12T20:14:11.31950Z,1321128851.3195 [SBIT](INFO): Initialize SBIT Component.
2011-11-12T20:14:11.32100Z,1321128851.321 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9356 $
2011-11-12T20:14:11.32160Z,1321128851.3216 [IBIT](INFO): Initialize IBIT Component.
2011-11-12T20:14:11.32490Z,1321128851.3249 [CBIT](DEBUG): Initialize CBIT Component.
2011-11-12T20:14:11.32520Z,1321128851.3252 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2011-11-12T20:14:11.35240Z,1321128851.3524 [Bathymetry](DEBUG): Initialize Bathymetry Derivation.
2011-11-12T20:14:11.35680Z,1321128851.3568 [Bathymetry](DEBUG): Opened 
2011-11-12T20:14:11.36560Z,1321128851.3656 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2011-11-12T20:14:11.36600Z,1321128851.366 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2011-11-12T20:14:11.36630Z,1321128851.3663 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2011-11-12T20:14:11.36690Z,1321128851.3669 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2011-11-12T20:14:11.36820Z,1321128851.3682 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2011-11-12T20:14:11.36860Z,1321128851.3686 [Navigation](DEBUG): Initializing Navigation.
2011-11-12T20:14:11.36890Z,1321128851.3689 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2011-11-12T20:14:11.38230Z,1321128851.3823 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2011-11-12T20:14:11.38510Z,1321128851.3851 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2011-11-12T20:14:11.38580Z,1321128851.3858 [LoopControl](DEBUG): Initialize LoopControlComponent.
2011-11-12T20:14:13.12840Z,1321128853.1284 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2011-11-12T20:14:13.13800Z,1321128853.138 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2011-11-12T20:14:13.14880Z,1321128853.1488 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2011-11-12T20:14:13.15830Z,1321128853.1583 [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>


2011-11-12T20:14:13.15920Z,1321128853.1592 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2011-11-12T20:14:13.18650Z,1321128853.1865 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2011-11-12T20:14:13.19000Z,1321128853.19 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2011-11-12T20:14:13.19600Z,1321128853.196 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2011-11-12T20:14:13.19930Z,1321128853.1993 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2011-11-12T20:14:13.20530Z,1321128853.2053 [Default:Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2011-11-12T20:14:13.21740Z,1321128853.2174 [Default:E.SetSpeed](DEBUG): Construct.
2011-11-12T20:14:13.22060Z,1321128853.2206 [Default:F.GoToSurface](DEBUG): Construct GoToSurface.
2011-11-12T20:14:13.22510Z,1321128853.2251 [Default:G.Wait](DEBUG): Construct Wait.
2011-11-12T20:14:13.22900Z,1321128853.229 [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">

    <Aggregate Id="GPS" >

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

    </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 on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped drop weight due to communications timeout</Syslog>
            </Timeout><Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="CallGPS" >

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

        <Call RefId="GPS"/>

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

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


2011-11-12T20:14:13.23420Z,1321128853.2342 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,AHRS_3DMGX3,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9601,Onboard,Radio_Freewave,DAT,WetLabsBB2FL,Depth_Keller,Bathymetry,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintainer,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger,
2011-11-12T20:14:13.25210Z,1321128853.2521 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2011-11-12T20:14:13.25850Z,1321128853.2585 [AHRS_3DMGX3](DEBUG): Initializing AHRS_3DMGX3.
2011-11-12T20:14:13.36760Z,1321128853.3676 [DVL_micro](DEBUG): Initializing DVL_micro.
2011-11-12T20:14:13.38750Z,1321128853.3875 [Radio_Freewave](INFO): Powering up
2011-11-12T20:14:13.39260Z,1321128853.3926 [DAT](INFO): Powering up
2011-11-12T20:14:13.39280Z,1321128853.3928 [DAT](DEBUG): Initializing DAT.
2011-11-12T20:14:13.39820Z,1321128853.3982 [WetLabsBB2FL](INFO): Powering down
2011-11-12T20:14:13.46370Z,1321128853.4637 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2011-11-12T20:14:13.46460Z,1321128853.4646 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2011-11-12T20:14:13.47330Z,1321128853.4733 [ElevatorServo](DEBUG): Initializing EZServoServo.
2011-11-12T20:14:13.47410Z,1321128853.4741 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2011-11-12T20:14:13.48210Z,1321128853.4821 [MassServo](DEBUG): Initializing EZServoServo.
2011-11-12T20:14:13.48290Z,1321128853.4829 [MassServo](DEBUG): Initializing MassServo.
2011-11-12T20:14:13.49020Z,1321128853.4902 [RudderServo](DEBUG): Initializing EZServoServo.
2011-11-12T20:14:13.49140Z,1321128853.4914 [RudderServo](DEBUG): Initializing RudderServo.
2011-11-12T20:14:13.49860Z,1321128853.4986 [ThrusterServo](DEBUG): Initializing EZServoServo.
2011-11-12T20:14:13.49960Z,1321128853.4996 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2011-11-12T20:14:16.31690Z,1321128856.3169 [NAL9601](INFO): Powering up NAL9601
2011-11-12T20:14:26.81530Z,1321128866.8153 [SBIT](IMPORTANT): Beginning Startup BIT
2011-11-12T20:14:26.81720Z,1321128866.8172 [CBIT](IMPORTANT): Beginning GF scan
2011-11-12T20:14:28.37020Z,1321128868.3702 [DAT](INFO): Powering down
2011-11-12T20:14:37.09380Z,1321128877.0938 [SBIT](FAULT): Mass: EXPECTED:0.0056 ACTUAL:0.001626595855
2011-11-12T20:14:53.07230Z,1321128893.0723 [CBIT](IMPORTANT): No ground fault detected
2011-11-12T20:15:08.99390Z,1321128908.9939 [SBIT](CRITICAL): SBIT FAILED
2011-11-12T20:15:09.39180Z,1321128909.3918 [MissionManager](IMPORTANT): Started mission Startup
2011-11-12T20:15:09.39190Z,1321128909.3919 [Startup] Running Loop=1
2011-11-12T20:15:09.39210Z,1321128909.3921 [Startup](INFO): Aggregate::initialize Startup
2011-11-12T20:15:09.39210Z,1321128909.3921 [Startup:A.GoToSurface] Running Loop=1
2011-11-12T20:15:09.39220Z,1321128909.3922 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:15:09.39750Z,1321128909.3975 [Startup:StartupSatComms] Running Loop=1
2011-11-12T20:15:09.39770Z,1321128909.3977 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2011-11-12T20:15:09.39780Z,1321128909.3978 [Startup:StartupSatComms:A] Running Loop=1
2011-11-12T20:15:09.79070Z,1321128909.7907 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2011-11-12T20:15:22.02770Z,1321128922.0277 [NAL9601](INFO): NAL9601 initialized
2011-11-12T20:15:23.20480Z,1321128923.2048 [NAL9601](IMPORTANT): GPS fix at: 1321128930
2011-11-12T20:15:23.21670Z,1321128923.2167 [Startup:StartupSatComms:A] Stopped
2011-11-12T20:15:23.21680Z,1321128923.2168 [Startup:StartupSatComms:B] Running Loop=1
2011-11-12T20:15:23.60100Z,1321128923.601 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2011-11-12T20:15:44.64220Z,1321128944.6422 [NAL9601](INFO): SBD MO Status=1, MOMSN=37362, MT Status=0, MTMSN=0
2011-11-12T20:15:44.77960Z,1321128944.7796 [NAL9601](INFO): Sent 245 bytes from file Logs/20111112T173436/shore0018.lzma
2011-11-12T20:15:44.77990Z,1321128944.7799 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:15:44.78120Z,1321128944.7812 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000000
2011-11-12T20:15:53.92190Z,1321128953.9219 [NAL9601](INFO): SBD MO Status=1, MOMSN=37363, MT Status=0, MTMSN=0
2011-11-12T20:15:54.06760Z,1321128954.0676 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0000.lzma
2011-11-12T20:15:54.06780Z,1321128954.0678 [NAL9601](INFO): Packets left to send: 1
2011-11-12T20:15:54.06890Z,1321128954.0689 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000001
2011-11-12T20:16:06.43280Z,1321128966.4328 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=37364, MT Status=1, MTMSN=3158
2011-11-12T20:16:06.65020Z,1321128966.6502 [NAL9601](INFO): Sent 238 bytes from file Logs/20111112T201406/shore0000.lzma
2011-11-12T20:16:06.65040Z,1321128966.6504 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:16:06.65150Z,1321128966.6515 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000002
2011-11-12T20:16:06.98910Z,1321128966.9891 [NAL9601](INFO): Received command:load Engineering/Homing.xml;set homing.Wpt1Lon -121.827 degree;run 
2011-11-12T20:16:07.00640Z,1321128967.0064 [CommandLine](IMPORTANT): got command load ./Missions/Engineering/Homing.xml
2011-11-12T20:16:07.00670Z,1321128967.0067 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/Homing.xml
2011-11-12T20:16:07.04600Z,1321128967.046 [MissionManager](INFO): DefineArg homing.Wpt1Lat = 36.8134 arcdeg
2011-11-12T20:16:07.04890Z,1321128967.0489 [MissionManager](INFO): DefineArg homing.Wpt1Lon = -121.8222 arcdeg
2011-11-12T20:16:07.05170Z,1321128967.0517 [MissionManager](INFO): DefineArg homing.Depth = 25 m
2011-11-12T20:16:07.05440Z,1321128967.0544 [MissionManager](INFO): DefineArg homing.Speed = 1 m/s
2011-11-12T20:16:07.05750Z,1321128967.0575 [MissionManager](INFO): DefineArg homing.MassDefault = -0.0044 n/a
2011-11-12T20:16:07.06060Z,1321128967.0606 [MissionManager](INFO): DefineArg homing.BuoyancyNeutral = 0.000457 n/a
2011-11-12T20:16:07.06340Z,1321128967.0634 [MissionManager](INFO): DefineArg homing.dockBearing = 10 arcdeg
2011-11-12T20:16:07.06620Z,1321128967.0662 [MissionManager](INFO): DefineArg homing.inTrkOffset = 0 m
2011-11-12T20:16:07.06900Z,1321128967.069 [MissionManager](INFO): DefineArg homing.xTrkOffset = 0 m
2011-11-12T20:16:07.07170Z,1321128967.0717 [MissionManager](INFO): DefineArg homing.finalApproach = 800 m
2011-11-12T20:16:07.07450Z,1321128967.0745 [MissionManager](INFO): DefineArg homing.clusterRadius = 20 m
2011-11-12T20:16:07.07630Z,1321128967.0763 [homing:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2011-11-12T20:16:07.08340Z,1321128967.0834 [homing:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2011-11-12T20:16:07.09110Z,1321128967.0911 [homing:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2011-11-12T20:16:07.09960Z,1321128967.0996 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml
2011-11-12T20:16:07.11710Z,1321128967.1171 [MissionManager](INFO): DefineArg homing:SURFACECOMMS.SurfaceDepthRate = nan m/s
2011-11-12T20:16:07.11990Z,1321128967.1199 [MissionManager](INFO): DefineArg homing:SURFACECOMMS.SurfacePitch = nan arcdeg
2011-11-12T20:16:07.12270Z,1321128967.1227 [MissionManager](INFO): DefineArg homing:SURFACECOMMS.SurfaceSpeed = 0.5 m/s
2011-11-12T20:16:07.12560Z,1321128967.1256 [MissionManager](INFO): DefineArg homing:SURFACECOMMS.IridiumTimeout = 30 min
2011-11-12T20:16:07.12670Z,1321128967.1267 [homing:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface.
2011-11-12T20:16:07.13840Z,1321128967.1384 [homing:WaypointOne:B.Pitch](DEBUG): Construct.
2011-11-12T20:16:07.14660Z,1321128967.1466 [homing:WaypointOne:C.Buoyancy](DEBUG): Construct Buoyancy.
2011-11-12T20:16:07.15030Z,1321128967.1503 [homing:WaypointOne:D.SetSpeed](DEBUG): Construct.
2011-11-12T20:16:07.15380Z,1321128967.1538 [homing:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Construct Waypoint.
2011-11-12T20:16:07.15790Z,1321128967.1579 [homing:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Construct Homing.
2011-11-12T20:16:07.18430Z,1321128967.1843 [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="homing">

<!-- Wpt1 d=74m; Wpt2 d=75m; Wpt3 d=77m -->

    <DefineArg Name="Wpt1Lat"><Units:degree/><Value>36.8134</Value></DefineArg>

    <DefineArg Name="Wpt1Lon"><Units:degree/><Value>-121.8222</Value></DefineArg>

    <DefineArg Name="Depth"><Units:meter/><Value>25</Value></DefineArg>

    <DefineArg Name="Speed"><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="MassDefault"><CustomUri Uri="Config/Control.massDefault"/></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><CustomUri Uri="Config/Control.buoyancyNeutral"/></DefineArg>

    <DefineArg Name="dockBearing"><Units:degree/><Value>10</Value></DefineArg>

    <DefineArg Name="inTrkOffset"><Units:meter/><Value>0</Value></DefineArg>

    <DefineArg Name="xTrkOffset"><Units:meter/><Value>0</Value></DefineArg>

    <DefineArg Name="finalApproach"><Units:meter/><Value>800</Value></DefineArg>

    <DefineArg Name="clusterRadius"><Units:meter/><Value>20</Value></DefineArg>

    <Timeout Duration="P40.0M"/>

    <Guidance:AltitudeEnvelope RunIn="Parallel">
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Units:meter/><Value>7</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>37</Value></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:OffshoreEnvelope RunIn="Parallel">
        <Setting><Guidance:OffshoreEnvelope.minOffshore/><Units:kilometer/><Value>1.0</Value></Setting>
    </Guidance:OffshoreEnvelope>

    <ReadData Strategy="AllDevices">
        <Universal:platform_orientation/>
    </ReadData>

    <Insert Filename="Insert/Surface.xml" Id="SURFACECOMMS" />

    <Aggregate Id="WaypointOne">

<!-- Home to Wpt1  -->

        <ReadData>
            <Universal:homing_sensor_communications/>
        </ReadData>

        <Guidance:Pitch RunIn="Parallel">
            <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
            <Setting><Guidance:Pitch.depth/><Arg Name="Depth"/></Setting>
        </Guidance:Pitch>

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

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

        <Guidance:Homing Id="WaypointW1" RunIn="Sequence">
            <Setting><Guidance:Homing.dockBearing/><Arg Name="dockBearing"/></Setting>
            <Setting><Guidance:Homing.inTrkOffset/><Arg Name="inTrkOffset"/></Setting>
            <Setting><Guidance:Homing.xTrkOffset/><Arg Name="xTrkOffset"/></Setting>
            <Setting><Guidance:Homing.finalApproach/><Arg Name="finalApproach"/></Setting>
            <Setting><Guidance:Homing.clusterRadius/><Arg Name="clusterRadius"/></Setting>
            <Setting><Guidance:Homing.latitude/><Arg Name="Wpt1Lat"/></Setting>
            <Setting><Guidance:Homing.longitude/><Arg Name="Wpt1Lon"/></Setting>
        </Guidance:Homing>

        <Call Id="PHONEHOMEWPT1" RefId="SURFACECOMMS"/>

    </Aggregate>

</Mission>


2011-11-12T20:16:07.18470Z,1321128967.1847 [CommandLine](IMPORTANT): Loaded ./Missions/Engineering/Homing.xml
2011-11-12T20:16:07.26670Z,1321128967.2667 [CommandLine](IMPORTANT): got command set homing.Wpt1Lon -121.8270035 degree
2011-11-12T20:16:07.26830Z,1321128967.2683 [CommandLine](IMPORTANT): got command run 
2011-11-12T20:16:07.26850Z,1321128967.2685 [CommandLine](IMPORTANT): Running 
2011-11-12T20:16:16.12190Z,1321128976.1219 [NAL9601](INFO): SBD MO Status=0, MOMSN=37365, MT Status=0, MTMSN=0
2011-11-12T20:16:23.91120Z,1321128983.9112 [Startup:StartupSatComms:B](INFO): Timed out from 2011-11-12T20:15:23.Z
2011-11-12T20:16:23.91130Z,1321128983.9113 [Startup:StartupSatComms:A_Timeout] Running Loop=1
2011-11-12T20:16:23.91150Z,1321128983.9115 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout
2011-11-12T20:16:23.91170Z,1321128983.9117 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout
2011-11-12T20:16:23.91180Z,1321128983.9118 [Startup:StartupSatComms:B] Stopped
2011-11-12T20:16:23.91200Z,1321128983.912 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2011-11-12T20:16:23.91200Z,1321128983.912 [Startup:StartupSatComms] Stopped
2011-11-12T20:16:23.91220Z,1321128983.9122 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2011-11-12T20:16:23.91270Z,1321128983.9127 [Startup](INFO): Completed Startup
2011-11-12T20:16:23.91280Z,1321128983.9128 [Startup] Stopped
2011-11-12T20:16:23.91290Z,1321128983.9129 [Startup](INFO): Aggregate::uninitialize Startup
2011-11-12T20:16:23.91300Z,1321128983.913 [Startup:A.GoToSurface] Stopped
2011-11-12T20:16:23.91300Z,1321128983.913 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:16:24.03130Z,1321128984.0313 [MissionManager](IMPORTANT): Started mission homing
2011-11-12T20:16:24.03140Z,1321128984.0314 [homing] Running Loop=1
2011-11-12T20:16:24.03150Z,1321128984.0315 [homing](INFO): Aggregate::initialize homing
2011-11-12T20:16:24.03160Z,1321128984.0316 [homing:A.AltitudeEnvelope] Running Loop=1
2011-11-12T20:16:24.03170Z,1321128984.0317 [homing:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2011-11-12T20:16:24.03190Z,1321128984.0319 [homing:B.DepthEnvelope] Running Loop=1
2011-11-12T20:16:24.03200Z,1321128984.032 [homing:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2011-11-12T20:16:24.03350Z,1321128984.0335 [homing:C.OffshoreEnvelope] Running Loop=1
2011-11-12T20:16:24.03350Z,1321128984.0335 [homing:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2011-11-12T20:16:24.03620Z,1321128984.0362 [homing:C.OffshoreEnvelope](DEBUG): Opened Resources/cencalShoreDist.nc
2011-11-12T20:16:24.04640Z,1321128984.0464 [homing:D] Running Loop=1
2011-11-12T20:16:24.04660Z,1321128984.0466 [homing:SURFACECOMMS] Running Loop=1
2011-11-12T20:16:24.04670Z,1321128984.0467 [homing:SURFACECOMMS](INFO): Aggregate::initialize homing:SURFACECOMMS
2011-11-12T20:16:24.04680Z,1321128984.0468 [homing:SURFACECOMMS:A.GoToSurface] Running Loop=1
2011-11-12T20:16:24.04690Z,1321128984.0469 [homing:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:16:24.05230Z,1321128984.0523 [homing:SURFACECOMMS:B] Running Loop=1
2011-11-12T20:16:24.05240Z,1321128984.0524 [homing:SURFACECOMMS:B](INFO): Aggregate::initialize homing:SURFACECOMMS:B
2011-11-12T20:16:24.05260Z,1321128984.0526 [homing:SURFACECOMMS:B:A] Running Loop=1
2011-11-12T20:16:24.05270Z,1321128984.0527 [homing:D] Running Loop=1
2011-11-12T20:16:24.05340Z,1321128984.0534 [homing:D](DEBUG): Initialize ReadDataComponent to sense platform_orientation
2011-11-12T20:16:24.05460Z,1321128984.0546 [homing:C.OffshoreEnvelope] Running Loop=1
2011-11-12T20:16:24.06010Z,1321128984.0601 [homing:B.DepthEnvelope] Running Loop=1
2011-11-12T20:16:24.06500Z,1321128984.065 [homing:A.AltitudeEnvelope] Running Loop=1
2011-11-12T20:16:24.41000Z,1321128984.41 [homing:SURFACECOMMS:B:A](DEBUG): Initialize ReadDataComponent to sense time_fix
2011-11-12T20:16:35.62100Z,1321128995.621 [NAL9601](INFO): SBD MO Status=1, MOMSN=37366, MT Status=0, MTMSN=0
2011-11-12T20:16:35.80360Z,1321128995.8036 [NAL9601](INFO): Sent 287 bytes from file Logs/20111112T201406/shore0001.lzma
2011-11-12T20:16:35.80380Z,1321128995.8038 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:16:35.80490Z,1321128995.8049 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000003
2011-11-12T20:16:42.03410Z,1321129002.0341 [NAL9601](INFO): SBD MO Status=0, MOMSN=37367, MT Status=0, MTMSN=0
2011-11-12T20:16:43.21550Z,1321129003.2155 [NAL9601](IMPORTANT): GPS fix at: 1321129011
2011-11-12T20:16:43.22780Z,1321129003.2278 [homing:SURFACECOMMS:B:A] Stopped
2011-11-12T20:16:43.22810Z,1321129003.2281 [homing:SURFACECOMMS:B:B] Running Loop=1
2011-11-12T20:16:43.62030Z,1321129003.6203 [homing:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2011-11-12T20:17:01.19690Z,1321129021.1969 [NAL9601](INFO): SBD MO Status=1, MOMSN=37368, MT Status=0, MTMSN=0
2011-11-12T20:17:01.36360Z,1321129021.3636 [NAL9601](INFO): Sent 149 bytes from file Logs/20111112T201406/shore0002.lzma
2011-11-12T20:17:01.36380Z,1321129021.3638 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:17:01.36490Z,1321129021.3649 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000004
2011-11-12T20:17:14.39040Z,1321129034.3904 [NAL9601](INFO): SBD MO Status=0, MOMSN=37369, MT Status=0, MTMSN=0
2011-11-12T20:17:14.55600Z,1321129034.556 [homing:SURFACECOMMS:B:B] Stopped
2011-11-12T20:17:14.55620Z,1321129034.5562 [homing:SURFACECOMMS:B:C] Running Loop=1
2011-11-12T20:17:14.80810Z,1321129034.8081 [homing:SURFACECOMMS:B:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2011-11-12T20:17:16.77640Z,1321129036.7764 [NAL9601](IMPORTANT): GPS fix at: 1321129044
2011-11-12T20:17:16.78910Z,1321129036.7891 [homing:SURFACECOMMS:B:C] Stopped
2011-11-12T20:17:16.78930Z,1321129036.7893 [homing:SURFACECOMMS:B](INFO): Completed homing:SURFACECOMMS:B
2011-11-12T20:17:16.78940Z,1321129036.7894 [homing:SURFACECOMMS:B] Stopped
2011-11-12T20:17:16.78950Z,1321129036.7895 [homing:SURFACECOMMS:B](INFO): Aggregate::uninitialize homing:SURFACECOMMS:B
2011-11-12T20:17:16.79000Z,1321129036.79 [homing:SURFACECOMMS](INFO): Completed homing:SURFACECOMMS
2011-11-12T20:17:16.79010Z,1321129036.7901 [homing:SURFACECOMMS] Stopped
2011-11-12T20:17:16.79020Z,1321129036.7902 [homing:SURFACECOMMS](INFO): Aggregate::uninitialize homing:SURFACECOMMS
2011-11-12T20:17:16.79030Z,1321129036.7903 [homing:SURFACECOMMS:A.GoToSurface] Stopped
2011-11-12T20:17:16.79030Z,1321129036.7903 [homing:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:17:16.79050Z,1321129036.7905 [homing:WaypointOne] Running Loop=1
2011-11-12T20:17:16.79060Z,1321129036.7906 [homing:WaypointOne](INFO): Aggregate::initialize homing:WaypointOne
2011-11-12T20:17:16.79070Z,1321129036.7907 [homing:WaypointOne:A] Running Loop=1
2011-11-12T20:17:16.79080Z,1321129036.7908 [homing:WaypointOne:B.Pitch] Running Loop=1
2011-11-12T20:17:16.79080Z,1321129036.7908 [homing:WaypointOne:B.Pitch](DEBUG): Initialize.
2011-11-12T20:17:16.79120Z,1321129036.7912 [homing:WaypointOne:C.Buoyancy] Running Loop=1
2011-11-12T20:17:16.79130Z,1321129036.7913 [homing:WaypointOne:C.Buoyancy](DEBUG): Initialize Buoyancy Component.
2011-11-12T20:17:16.79180Z,1321129036.7918 [homing:WaypointOne:D.SetSpeed] Running Loop=1
2011-11-12T20:17:16.79190Z,1321129036.7919 [homing:WaypointOne:D.SetSpeed](DEBUG): Initialize.
2011-11-12T20:17:16.79220Z,1321129036.7922 [homing:WaypointOne:WaypointW1.HomingWaypoint] Running Loop=1
2011-11-12T20:17:16.79220Z,1321129036.7922 [homing:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Initialize HomingComponent.
2011-11-12T20:17:16.79240Z,1321129036.7924 [homing:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Initialize WaypointComponent.
2011-11-12T20:17:17.18910Z,1321129037.1891 [homing:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon is in the DAT FOV with dtw = 671.76. Turning DAT on.
2011-11-12T20:17:17.19410Z,1321129037.1941 [homing:WaypointOne:D.SetSpeed] Running Loop=1
2011-11-12T20:17:17.19820Z,1321129037.1982 [homing:WaypointOne:C.Buoyancy] Running Loop=1
2011-11-12T20:17:17.20250Z,1321129037.2025 [homing:WaypointOne:B.Pitch] Running Loop=1
2011-11-12T20:17:17.20730Z,1321129037.2073 [homing:WaypointOne:A] Running Loop=1
2011-11-12T20:17:17.20790Z,1321129037.2079 [homing:WaypointOne:A](DEBUG): Initialize ReadDataComponent to sense homing_sensor_communications
2011-11-12T20:17:17.56470Z,1321129037.5647 [DAT](INFO): Powering up
2011-11-12T20:17:23.19530Z,1321129043.1953 [NAL9601](INFO): Powering down
2011-11-12T20:17:36.78490Z,1321129056.7849 [Radio_Freewave](INFO): Powering down
2011-11-12T20:17:44.43120Z,1321129064.4312 [DAT](ERROR): No response from remote modem
2011-11-12T20:18:49.64010Z,1321129129.6401 [Batt_Ocean_Server](FAULT): Over Temperature Alarm! Battery Bank #0 STATUS: 5911
2011-11-12T20:18:49.64050Z,1321129129.6405 [Batt_Ocean_Server](FAULT): Not Initialized - Battery Bank #0 STATUS: 5911
2011-11-12T20:19:04.88320Z,1321129144.8832 [DAT](ERROR): No response from remote modem
2011-11-12T20:20:30.09520Z,1321129230.0952 [DAT](ERROR): No response from remote modem
2011-11-12T20:21:03.67520Z,1321129263.6752 [DAT](ERROR): No response from remote modem
2011-11-12T20:29:19.66790Z,1321129759.6679 [homing:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Should end now. Shutting off the DAT.  dtw = -0.1 m.
2011-11-12T20:29:19.66850Z,1321129759.6685 [homing:WaypointOne:WaypointW1.HomingWaypoint](INFO): Homing::Reached Waypoint 36.8134,-121.826997
2011-11-12T20:29:19.66870Z,1321129759.6687 [homing:WaypointOne:WaypointW1.HomingWaypoint] Stopped
2011-11-12T20:29:19.66880Z,1321129759.6688 [homing:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Uninitialize HomingComponent.
2011-11-12T20:29:19.66900Z,1321129759.669 [homing:WaypointOne:PHONEHOMEWPT1] Running Loop=1
2011-11-12T20:29:19.66910Z,1321129759.6691 [homing:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::initialize homing:WaypointOne:PHONEHOMEWPT1
2011-11-12T20:29:20.02420Z,1321129760.0242 [homing:SURFACECOMMS] Running Loop=1
2011-11-12T20:29:20.02440Z,1321129760.0244 [homing:SURFACECOMMS](INFO): Aggregate::initialize homing:SURFACECOMMS
2011-11-12T20:29:20.02450Z,1321129760.0245 [homing:SURFACECOMMS:A.GoToSurface] Running Loop=1
2011-11-12T20:29:20.02460Z,1321129760.0246 [homing:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:33:24.93660Z,1321130004.9366 [Radio_Freewave](INFO): Powering up
2011-11-12T20:33:24.94610Z,1321130004.9461 [homing:SURFACECOMMS:B] Running Loop=1
2011-11-12T20:33:24.94620Z,1321130004.9462 [homing:SURFACECOMMS:B](INFO): Aggregate::initialize homing:SURFACECOMMS:B
2011-11-12T20:33:24.94640Z,1321130004.9464 [homing:SURFACECOMMS:B:A] Running Loop=1
2011-11-12T20:33:25.74390Z,1321130005.7439 [NAL9601](INFO): Powering up
2011-11-12T20:34:31.45570Z,1321130071.4557 [NAL9601](INFO): NAL9601 initialized
2011-11-12T20:34:32.60320Z,1321130072.6032 [NAL9601](IMPORTANT): GPS fix at: 1321130082
2011-11-12T20:34:32.63940Z,1321130072.6394 [homing:SURFACECOMMS:B:A] Stopped
2011-11-12T20:34:32.63960Z,1321130072.6396 [homing:SURFACECOMMS:B:B] Running Loop=1
2011-11-12T20:34:48.85760Z,1321130088.8576 [NAL9601](INFO): SBD MO Status=1, MOMSN=37370, MT Status=0, MTMSN=0
2011-11-12T20:34:49.01960Z,1321130089.0196 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0003.lzma
2011-11-12T20:34:49.01980Z,1321130089.0198 [NAL9601](INFO): Packets left to send: 5
2011-11-12T20:34:49.02160Z,1321130089.0216 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000005
2011-11-12T20:35:00.55400Z,1321130100.554 [NAL9601](INFO): SBD MO Status=1, MOMSN=37371, MT Status=0, MTMSN=0
2011-11-12T20:35:00.70360Z,1321130100.7036 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0003.lzma
2011-11-12T20:35:00.70380Z,1321130100.7038 [NAL9601](INFO): Packets left to send: 4
2011-11-12T20:35:00.70560Z,1321130100.7056 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000006
2011-11-12T20:35:03.84320Z,1321130103.8432 [DAT](ERROR): No response from remote modem
2011-11-12T20:35:07.92890Z,1321130107.9289 [NAL9601](INFO): SBD MO Status=1, MOMSN=37372, MT Status=0, MTMSN=0
2011-11-12T20:35:08.08760Z,1321130108.0876 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0003.lzma
2011-11-12T20:35:08.08780Z,1321130108.0878 [NAL9601](INFO): Packets left to send: 3
2011-11-12T20:35:08.08890Z,1321130108.0889 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000007
2011-11-12T20:35:18.43470Z,1321130118.4347 [NAL9601](INFO): SBD MO Status=1, MOMSN=37373, MT Status=0, MTMSN=0
2011-11-12T20:35:18.57160Z,1321130118.5716 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0003.lzma
2011-11-12T20:35:18.57180Z,1321130118.5718 [NAL9601](INFO): Packets left to send: 2
2011-11-12T20:35:18.57290Z,1321130118.5729 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000008
2011-11-12T20:35:26.13760Z,1321130126.1376 [NAL9601](INFO): SBD MO Status=1, MOMSN=37374, MT Status=0, MTMSN=0
2011-11-12T20:35:26.25960Z,1321130126.2596 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0003.lzma
2011-11-12T20:35:26.25980Z,1321130126.2598 [NAL9601](INFO): Packets left to send: 1
2011-11-12T20:35:26.26090Z,1321130126.2609 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000009
2011-11-12T20:35:29.03520Z,1321130129.0352 [DAT](ERROR): No response from remote modem
2011-11-12T20:35:39.52600Z,1321130139.526 [NAL9601](INFO): SBD MO Status=1, MOMSN=37375, MT Status=0, MTMSN=0
2011-11-12T20:35:39.73560Z,1321130139.7356 [NAL9601](INFO): Sent 23 bytes from file Logs/20111112T201406/shore0003.lzma
2011-11-12T20:35:39.73580Z,1321130139.7358 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:35:39.73690Z,1321130139.7369 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000010
2011-11-12T20:35:41.59120Z,1321130141.5912 [DAT](ERROR): No response from remote modem
2011-11-12T20:35:49.57400Z,1321130149.574 [NAL9601](INFO): SBD MO Status=0, MOMSN=37376, MT Status=0, MTMSN=0
2011-11-12T20:35:49.73560Z,1321130149.7356 [homing:SURFACECOMMS:B:B] Stopped
2011-11-12T20:35:49.73580Z,1321130149.7358 [homing:SURFACECOMMS:B:C] Running Loop=1
2011-11-12T20:35:51.93990Z,1321130151.9399 [NAL9601](IMPORTANT): GPS fix at: 1321130161
2011-11-12T20:35:51.95370Z,1321130151.9537 [homing:SURFACECOMMS:B:C] Stopped
2011-11-12T20:35:51.95390Z,1321130151.9539 [homing:SURFACECOMMS:B](INFO): Completed homing:SURFACECOMMS:B
2011-11-12T20:35:51.95400Z,1321130151.954 [homing:SURFACECOMMS:B] Stopped
2011-11-12T20:35:51.95410Z,1321130151.9541 [homing:SURFACECOMMS:B](INFO): Aggregate::uninitialize homing:SURFACECOMMS:B
2011-11-12T20:35:51.95460Z,1321130151.9546 [homing:SURFACECOMMS](INFO): Completed homing:SURFACECOMMS
2011-11-12T20:35:51.95460Z,1321130151.9546 [homing:SURFACECOMMS] Stopped
2011-11-12T20:35:51.95480Z,1321130151.9548 [homing:SURFACECOMMS](INFO): Aggregate::uninitialize homing:SURFACECOMMS
2011-11-12T20:35:51.95490Z,1321130151.9549 [homing:SURFACECOMMS:A.GoToSurface] Stopped
2011-11-12T20:35:51.95490Z,1321130151.9549 [homing:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:35:52.33540Z,1321130152.3354 [homing:WaypointOne:PHONEHOMEWPT1](INFO): Completed homing:WaypointOne:PHONEHOMEWPT1
2011-11-12T20:35:52.33550Z,1321130152.3355 [homing:WaypointOne:PHONEHOMEWPT1] Stopped
2011-11-12T20:35:52.33570Z,1321130152.3357 [homing:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::uninitialize homing:WaypointOne:PHONEHOMEWPT1
2011-11-12T20:35:52.33700Z,1321130152.337 [homing:WaypointOne](INFO): Completed homing:WaypointOne
2011-11-12T20:35:52.33700Z,1321130152.337 [homing:WaypointOne] Stopped
2011-11-12T20:35:52.33720Z,1321130152.3372 [homing:WaypointOne](INFO): Aggregate::uninitialize homing:WaypointOne
2011-11-12T20:35:52.33720Z,1321130152.3372 [homing:WaypointOne:A] Stopped
2011-11-12T20:35:52.33730Z,1321130152.3373 [homing:WaypointOne:B.Pitch] Stopped
2011-11-12T20:35:52.33730Z,1321130152.3373 [homing:WaypointOne:C.Buoyancy] Stopped
2011-11-12T20:35:52.33740Z,1321130152.3374 [homing:WaypointOne:C.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2011-11-12T20:35:52.33750Z,1321130152.3375 [homing:WaypointOne:D.SetSpeed] Stopped
2011-11-12T20:35:52.33760Z,1321130152.3376 [homing:WaypointOne:D.SetSpeed](DEBUG): Uninitialize.
2011-11-12T20:35:52.33880Z,1321130152.3388 [homing](INFO): Completed homing
2011-11-12T20:35:52.33890Z,1321130152.3389 [homing] Stopped
2011-11-12T20:35:52.33910Z,1321130152.3391 [homing](INFO): Aggregate::uninitialize homing
2011-11-12T20:35:52.33920Z,1321130152.3392 [homing:A.AltitudeEnvelope] Stopped
2011-11-12T20:35:52.33930Z,1321130152.3393 [homing:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2011-11-12T20:35:52.33940Z,1321130152.3394 [homing:B.DepthEnvelope] Stopped
2011-11-12T20:35:52.33940Z,1321130152.3394 [homing:B.DepthEnvelope](DEBUG): Uninitialize.
2011-11-12T20:35:52.33950Z,1321130152.3395 [homing:C.OffshoreEnvelope] Stopped
2011-11-12T20:35:52.33960Z,1321130152.3396 [homing:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2011-11-12T20:35:52.34020Z,1321130152.3402 [homing:D] Stopped
2011-11-12T20:35:52.73540Z,1321130152.7354 [MissionManager](IMPORTANT): Started mission Default
2011-11-12T20:35:52.73550Z,1321130152.7355 [Default] Running Loop=1
2011-11-12T20:35:52.73560Z,1321130152.7356 [Default](INFO): Aggregate::initialize Default
2011-11-12T20:35:52.73570Z,1321130152.7357 [Default:E.SetSpeed] Running Loop=1
2011-11-12T20:35:52.73580Z,1321130152.7358 [Default:E.SetSpeed](DEBUG): Initialize.
2011-11-12T20:35:52.73590Z,1321130152.7359 [Default:F.GoToSurface] Running Loop=1
2011-11-12T20:35:52.73600Z,1321130152.736 [Default:F.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:35:52.73640Z,1321130152.7364 [Default:GPS] Running Loop=1
2011-11-12T20:35:52.73660Z,1321130152.7366 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2011-11-12T20:35:52.73660Z,1321130152.7366 [Default:GPS:A.SetSpeed] Running Loop=1
2011-11-12T20:35:52.73670Z,1321130152.7367 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2011-11-12T20:35:52.73690Z,1321130152.7369 [Default:GPS:B.GoToSurface] Running Loop=1
2011-11-12T20:35:52.73700Z,1321130152.737 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:35:52.73780Z,1321130152.7378 [Default:F.GoToSurface] Running Loop=1
2011-11-12T20:35:52.74250Z,1321130152.7425 [Default:E.SetSpeed] Running Loop=1
2011-11-12T20:35:52.75100Z,1321130152.751 [Default:GPS:B.GoToSurface] Stopped
2011-11-12T20:35:52.75120Z,1321130152.7512 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:35:52.75130Z,1321130152.7513 [Default:GPS:Read_GPS] Running Loop=1
2011-11-12T20:35:52.75140Z,1321130152.7514 [Default:GPS:A.SetSpeed] Running Loop=1
2011-11-12T20:35:53.20370Z,1321130153.2037 [DAT](INFO): Powering down
2011-11-12T20:35:53.21240Z,1321130153.2124 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2011-11-12T20:35:55.11560Z,1321130155.1156 [NAL9601](IMPORTANT): GPS fix at: 1321130164
2011-11-12T20:35:55.12810Z,1321130155.1281 [Default:GPS:Read_GPS] Stopped
2011-11-12T20:35:55.12860Z,1321130155.1286 [Default:GPS](INFO): Completed Default:GPS
2011-11-12T20:35:55.12860Z,1321130155.1286 [Default:GPS] Stopped
2011-11-12T20:35:55.12880Z,1321130155.1288 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2011-11-12T20:35:55.12890Z,1321130155.1289 [Default:GPS:A.SetSpeed] Stopped
2011-11-12T20:35:55.12890Z,1321130155.1289 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T20:35:55.12910Z,1321130155.1291 [Default:Iridium] Running Loop=1
2011-11-12T20:35:55.12920Z,1321130155.1292 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2011-11-12T20:35:55.12930Z,1321130155.1293 [Default:Iridium:A.SetSpeed] Running Loop=1
2011-11-12T20:35:55.12940Z,1321130155.1294 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2011-11-12T20:35:55.12960Z,1321130155.1296 [Default:Iridium:B.GoToSurface] Running Loop=1
2011-11-12T20:35:55.12970Z,1321130155.1297 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:35:55.52440Z,1321130155.5244 [Default:Iridium:B.GoToSurface] Stopped
2011-11-12T20:35:55.52450Z,1321130155.5245 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:35:55.52470Z,1321130155.5247 [Default:Iridium:Read_Iridium] Running Loop=1
2011-11-12T20:35:55.52470Z,1321130155.5247 [Default:Iridium:A.SetSpeed] Running Loop=1
2011-11-12T20:35:55.92990Z,1321130155.9299 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2011-11-12T20:36:05.75680Z,1321130165.7568 [NAL9601](INFO): SBD MO Status=1, MOMSN=37377, MT Status=0, MTMSN=0
2011-11-12T20:36:05.89560Z,1321130165.8956 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0004.lzma
2011-11-12T20:36:05.89580Z,1321130165.8958 [NAL9601](INFO): Packets left to send: 1
2011-11-12T20:36:05.89690Z,1321130165.8969 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000011
2011-11-12T20:36:15.83800Z,1321130175.838 [NAL9601](INFO): SBD MO Status=1, MOMSN=37378, MT Status=0, MTMSN=0
2011-11-12T20:36:15.98370Z,1321130175.9837 [NAL9601](INFO): Sent 41 bytes from file Logs/20111112T201406/shore0004.lzma
2011-11-12T20:36:15.98390Z,1321130175.9839 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:36:15.98500Z,1321130175.985 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000012
2011-11-12T20:36:23.83790Z,1321130183.8379 [NAL9601](INFO): SBD MO Status=0, MOMSN=37379, MT Status=0, MTMSN=0
2011-11-12T20:36:23.98220Z,1321130183.9822 [Default:Iridium:Read_Iridium] Stopped
2011-11-12T20:36:23.98260Z,1321130183.9826 [Default:Iridium](INFO): Completed Default:Iridium
2011-11-12T20:36:23.98270Z,1321130183.9827 [Default:Iridium] Stopped
2011-11-12T20:36:23.98280Z,1321130183.9828 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2011-11-12T20:36:23.98290Z,1321130183.9829 [Default:Iridium:A.SetSpeed] Stopped
2011-11-12T20:36:23.98300Z,1321130183.983 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T20:36:23.98320Z,1321130183.9832 [Default:G.Wait] Running Loop=1
2011-11-12T20:36:23.98320Z,1321130183.9832 [Default:G.Wait](DEBUG): Initialize Wait Component.
2011-11-12T20:36:34.52870Z,1321130194.5287 [NAL9601](INFO): Powering down
2011-11-12T20:41:24.54020Z,1321130484.5402 [Default:CallIridium] Running Loop=1
2011-11-12T20:41:24.54040Z,1321130484.5404 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2011-11-12T20:41:24.54060Z,1321130484.5406 [Default:CallIridium:A] Running Loop=1
2011-11-12T20:41:24.54070Z,1321130484.5407 [Default:CallIridium:A](INFO): Aggregate::initialize Default:CallIridium:A
2011-11-12T20:41:24.54080Z,1321130484.5408 [Default:CallGPS] Running Loop=1
2011-11-12T20:41:24.54100Z,1321130484.541 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS
2011-11-12T20:41:24.54120Z,1321130484.5412 [Default:CallGPS:A] Running Loop=1
2011-11-12T20:41:24.54130Z,1321130484.5413 [Default:CallGPS:A](INFO): Aggregate::initialize Default:CallGPS:A
2011-11-12T20:41:29.48980Z,1321130489.4898 [Default:Iridium] Running Loop=1
2011-11-12T20:41:29.49000Z,1321130489.49 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2011-11-12T20:41:29.49010Z,1321130489.4901 [Default:Iridium:A.SetSpeed] Running Loop=1
2011-11-12T20:41:29.49020Z,1321130489.4902 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2011-11-12T20:41:29.49030Z,1321130489.4903 [Default:Iridium:B.GoToSurface] Running Loop=1
2011-11-12T20:41:29.49040Z,1321130489.4904 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:41:29.49110Z,1321130489.4911 [Default:Iridium:B.GoToSurface] Stopped
2011-11-12T20:41:29.49120Z,1321130489.4912 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:41:29.49140Z,1321130489.4914 [Default:Iridium:Read_Iridium] Running Loop=1
2011-11-12T20:41:29.49160Z,1321130489.4916 [Default:GPS] Running Loop=1
2011-11-12T20:41:29.49180Z,1321130489.4918 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2011-11-12T20:41:29.49190Z,1321130489.4919 [Default:GPS:A.SetSpeed] Running Loop=1
2011-11-12T20:41:29.49190Z,1321130489.4919 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2011-11-12T20:41:29.49210Z,1321130489.4921 [Default:GPS:B.GoToSurface] Running Loop=1
2011-11-12T20:41:29.49220Z,1321130489.4922 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:41:29.49280Z,1321130489.4928 [Default:GPS:B.GoToSurface] Stopped
2011-11-12T20:41:29.49280Z,1321130489.4928 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:41:29.49300Z,1321130489.493 [Default:GPS:Read_GPS] Running Loop=1
2011-11-12T20:41:30.09970Z,1321130490.0997 [NAL9601](INFO): Powering up
2011-11-12T20:42:35.81180Z,1321130555.8118 [NAL9601](INFO): NAL9601 initialized
2011-11-12T20:42:55.19410Z,1321130575.1941 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=37380, MT Status=1, MTMSN=3159
2011-11-12T20:42:55.36760Z,1321130575.3676 [NAL9601](INFO): Sent 150 bytes from file Logs/20111112T201406/shore0005.lzma
2011-11-12T20:42:55.36780Z,1321130575.3678 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:42:55.36890Z,1321130575.3689 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000013
2011-11-12T20:42:55.78470Z,1321130575.7847 [NAL9601](INFO): Received command:run Transport/transit_3km.xml
2011-11-12T20:42:55.81160Z,1321130575.8116 [CommandLine](IMPORTANT): got command run ./Missions/Transport/transit_3km.xml
2011-11-12T20:42:55.81190Z,1321130575.8119 [MissionManager](INFO): Loading Mission: ./Missions/Transport/transit_3km.xml
2011-11-12T20:42:55.84170Z,1321130575.8417 [MissionManager](INFO): DefineArg transit_3km.ApproachDepth = 10 m
2011-11-12T20:42:55.84920Z,1321130575.8492 [MissionManager](INFO): DefineArg transit_3km.Wpt1Lat = 36.806966 arcdeg
2011-11-12T20:42:55.85220Z,1321130575.8522 [MissionManager](INFO): DefineArg transit_3km.Wpt1Lon = -121.824326 arcdeg
2011-11-12T20:42:55.85490Z,1321130575.8549 [MissionManager](INFO): DefineArg transit_3km.Speed = 1 m/s
2011-11-12T20:42:55.85640Z,1321130575.8564 [transit_3km:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2011-11-12T20:42:55.87560Z,1321130575.8756 [transit_3km:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2011-11-12T20:42:55.88270Z,1321130575.8827 [transit_3km:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2011-11-12T20:42:55.90290Z,1321130575.9029 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface.
2011-11-12T20:42:55.92440Z,1321130575.9244 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Construct.
2011-11-12T20:42:55.94820Z,1321130575.9482 [transit_3km:WaypointOne:A.Pitch](DEBUG): Construct.
2011-11-12T20:42:55.95610Z,1321130575.9561 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Construct.
2011-11-12T20:42:55.97140Z,1321130575.9714 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Construct Waypoint.
2011-11-12T20:42:55.99340Z,1321130575.9934 [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="transit_3km">

<!-- To be used within 6km of waypoint. No science collection.  -->

    <DefineArg Name="ApproachDepth"><Units:meter /><Value>10.0</Value></DefineArg>

    <DefineArg Name="Wpt1Lat"><Units:degree /><Value>36.806966</Value></DefineArg>

    <DefineArg Name="Wpt1Lon"><Units:degree /><Value>-121.824326</Value></DefineArg>

    <DefineArg Name="Speed"><Units:meter_per_second/><Value>1</Value></DefineArg>

    <Timeout Duration="P130M" />

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

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

    <Guidance:OffshoreEnvelope RunIn="Parallel">
        <Setting><Guidance:OffshoreEnvelope.minOffshore/><Units:kilometer/><Value>1</Value></Setting>
    </Guidance:OffshoreEnvelope>

    <Aggregate Id="SURFACECOMMS">

        <Guidance:GoToSurface RunIn="Progression" />

        <Aggregate>

            <Preemptive><True /></Preemptive>

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

            <ReadDatum><Universal:latitude_fix />
            </ReadDatum>

            <ReadDatum>
                <Timeout Duration="P30M">
                    <Assign Id="TouchComms"><Universal:platform_communications/></Assign>
                </Timeout><Universal:platform_communications />
            </ReadDatum>

            <ReadDatum><Universal:latitude_fix />
            </ReadDatum>

        </Aggregate>

    </Aggregate>

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

    <Aggregate Id="NeedComms">

        <When>
            <Elapsed><Universal:time_fix /></Elapsed>
            <Gt><Units:minute/><Value>35</Value></Gt>
        </When>

        <Call Id="NEEDCOMMS" RefId="SURFACECOMMS" />

    </Aggregate>

    <Aggregate Id="WaypointOne">

<!-- Go to Wpt1 -->

        <Guidance:Pitch RunIn="Parallel">
            <Setting><Guidance:Pitch.depth /><Arg Name="ApproachDepth" /></Setting>
        </Guidance:Pitch>

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

        <Guidance:Waypoint Id="WaypointW1" RunIn="Sequence">
            <Setting><Guidance:Waypoint.latitude /><Arg Name="Wpt1Lat" /></Setting>
            <Setting><Guidance:Waypoint.longitude /><Arg Name="Wpt1Lon" /></Setting>
        </Guidance:Waypoint>

        <Call Id="PHONEHOMEWPT1" RefId="SURFACECOMMS" />

    </Aggregate>

</Mission>


2011-11-12T20:42:55.99390Z,1321130575.9939 [CommandLine](IMPORTANT): Running ./Missions/Transport/transit_3km.xml
2011-11-12T20:42:56.07050Z,1321130576.0705 [Default] Stopped
2011-11-12T20:42:56.07070Z,1321130576.0707 [Default](INFO): Aggregate::uninitialize Default
2011-11-12T20:42:56.07080Z,1321130576.0708 [Default:GPS] Stopped
2011-11-12T20:42:56.07090Z,1321130576.0709 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2011-11-12T20:42:56.07100Z,1321130576.071 [Default:GPS:A.SetSpeed] Stopped
2011-11-12T20:42:56.07100Z,1321130576.071 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T20:42:56.07110Z,1321130576.0711 [Default:GPS:Read_GPS] Stopped
2011-11-12T20:42:56.07120Z,1321130576.0712 [Default:Iridium] Stopped
2011-11-12T20:42:56.07130Z,1321130576.0713 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2011-11-12T20:42:56.07140Z,1321130576.0714 [Default:Iridium:A.SetSpeed] Stopped
2011-11-12T20:42:56.07150Z,1321130576.0715 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T20:42:56.07150Z,1321130576.0715 [Default:Iridium:Read_Iridium] Stopped
2011-11-12T20:42:56.07160Z,1321130576.0716 [Default:CallGPS] Stopped
2011-11-12T20:42:56.07170Z,1321130576.0717 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS
2011-11-12T20:42:56.07180Z,1321130576.0718 [Default:CallGPS:A] Stopped
2011-11-12T20:42:56.07190Z,1321130576.0719 [Default:CallGPS:A](INFO): Aggregate::uninitialize Default:CallGPS:A
2011-11-12T20:42:56.07200Z,1321130576.072 [Default:CallIridium] Stopped
2011-11-12T20:42:56.07210Z,1321130576.0721 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2011-11-12T20:42:56.07220Z,1321130576.0722 [Default:CallIridium:A] Stopped
2011-11-12T20:42:56.07230Z,1321130576.0723 [Default:CallIridium:A](INFO): Aggregate::uninitialize Default:CallIridium:A
2011-11-12T20:42:56.07240Z,1321130576.0724 [Default:E.SetSpeed] Stopped
2011-11-12T20:42:56.07250Z,1321130576.0725 [Default:E.SetSpeed](DEBUG): Uninitialize.
2011-11-12T20:42:56.07250Z,1321130576.0725 [Default:F.GoToSurface] Stopped
2011-11-12T20:42:56.07260Z,1321130576.0726 [Default:F.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:42:56.07270Z,1321130576.0727 [Default:G.Wait] Stopped
2011-11-12T20:42:56.07270Z,1321130576.0727 [Default:G.Wait](DEBUG): Uninitialize Wait Component.
2011-11-12T20:42:56.07290Z,1321130576.0729 [MissionManager](IMPORTANT): Started mission transit_3km
2011-11-12T20:42:56.07300Z,1321130576.073 [transit_3km] Running Loop=1
2011-11-12T20:42:56.07310Z,1321130576.0731 [transit_3km](INFO): Aggregate::initialize transit_3km
2011-11-12T20:42:56.07320Z,1321130576.0732 [transit_3km:A.AltitudeEnvelope] Running Loop=1
2011-11-12T20:42:56.07320Z,1321130576.0732 [transit_3km:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2011-11-12T20:42:56.07340Z,1321130576.0734 [transit_3km:B.DepthEnvelope] Running Loop=1
2011-11-12T20:42:56.07340Z,1321130576.0734 [transit_3km:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2011-11-12T20:42:56.07460Z,1321130576.0746 [transit_3km:C.OffshoreEnvelope] Running Loop=1
2011-11-12T20:42:56.07470Z,1321130576.0747 [transit_3km:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2011-11-12T20:42:56.07710Z,1321130576.0771 [transit_3km:C.OffshoreEnvelope](DEBUG): Opened Resources/cencalShoreDist.nc
2011-11-12T20:42:56.08910Z,1321130576.0891 [transit_3km:SURFACECOMMS] Running Loop=1
2011-11-12T20:42:56.08920Z,1321130576.0892 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS
2011-11-12T20:42:56.08930Z,1321130576.0893 [transit_3km:SURFACECOMMS:A.GoToSurface] Running Loop=1
2011-11-12T20:42:56.08940Z,1321130576.0894 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T20:42:56.09470Z,1321130576.0947 [transit_3km:SURFACECOMMS:B] Running Loop=1
2011-11-12T20:42:56.09480Z,1321130576.0948 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:B
2011-11-12T20:42:56.09490Z,1321130576.0949 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1
2011-11-12T20:42:56.09490Z,1321130576.0949 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Initialize.
2011-11-12T20:42:56.09520Z,1321130576.0952 [transit_3km:SURFACECOMMS:B:B] Running Loop=1
2011-11-12T20:42:56.09530Z,1321130576.0953 [transit_3km:C.OffshoreEnvelope] Running Loop=1
2011-11-12T20:42:56.10020Z,1321130576.1002 [transit_3km:B.DepthEnvelope] Running Loop=1
2011-11-12T20:42:56.10490Z,1321130576.1049 [transit_3km:A.AltitudeEnvelope] Running Loop=1
2011-11-12T20:42:56.47310Z,1321130576.4731 [transit_3km:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2011-11-12T20:42:56.47440Z,1321130576.4744 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1
2011-11-12T20:44:48.90320Z,1321130688.9032 [NAL9601](IMPORTANT): GPS fix at: 1321130699
2011-11-12T20:44:48.91560Z,1321130688.9156 [transit_3km:SURFACECOMMS:B:B] Stopped
2011-11-12T20:44:48.91580Z,1321130688.9158 [transit_3km:SURFACECOMMS:B:C] Running Loop=1
2011-11-12T20:44:49.29020Z,1321130689.2902 [transit_3km:SURFACECOMMS:B:C](DEBUG): Initialize ReadDataComponent to sense platform_communications
2011-11-12T20:44:55.04210Z,1321130695.0421 [NAL9601](INFO): SBD MO Status=0, MOMSN=37381, MT Status=0, MTMSN=0
2011-11-12T20:45:07.29800Z,1321130707.298 [NAL9601](INFO): SBD MO Status=1, MOMSN=37382, MT Status=0, MTMSN=0
2011-11-12T20:45:07.46360Z,1321130707.4636 [NAL9601](INFO): Sent 328 bytes from file Logs/20111112T201406/shore0006.lzma
2011-11-12T20:45:07.46380Z,1321130707.4638 [NAL9601](INFO): Packets left to send: 0
2011-11-12T20:45:07.46490Z,1321130707.4649 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000014
2011-11-12T20:45:16.49290Z,1321130716.4929 [NAL9601](INFO): SBD MO Status=0, MOMSN=37383, MT Status=0, MTMSN=0
2011-11-12T20:45:16.66330Z,1321130716.6633 [transit_3km:SURFACECOMMS:B:C] Stopped
2011-11-12T20:45:16.66350Z,1321130716.6635 [transit_3km:SURFACECOMMS:B:D] Running Loop=1
2011-11-12T20:45:16.90410Z,1321130716.9041 [transit_3km:SURFACECOMMS:B:D](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2011-11-12T20:45:18.89970Z,1321130718.8997 [NAL9601](IMPORTANT): GPS fix at: 1321130729
2011-11-12T20:45:18.91210Z,1321130718.9121 [transit_3km:SURFACECOMMS:B:D] Stopped
2011-11-12T20:45:18.91250Z,1321130718.9125 [transit_3km:SURFACECOMMS:B](INFO): Completed transit_3km:SURFACECOMMS:B
2011-11-12T20:45:18.91260Z,1321130718.9126 [transit_3km:SURFACECOMMS:B] Stopped
2011-11-12T20:45:18.91270Z,1321130718.9127 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:B
2011-11-12T20:45:18.91280Z,1321130718.9128 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Stopped
2011-11-12T20:45:18.91290Z,1321130718.9129 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T20:45:18.91330Z,1321130718.9133 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS
2011-11-12T20:45:18.91340Z,1321130718.9134 [transit_3km:SURFACECOMMS] Stopped
2011-11-12T20:45:18.91350Z,1321130718.9135 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS
2011-11-12T20:45:18.91360Z,1321130718.9136 [transit_3km:SURFACECOMMS:A.GoToSurface] Stopped
2011-11-12T20:45:18.91370Z,1321130718.9137 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T20:45:18.91380Z,1321130718.9138 [transit_3km:WaypointOne] Running Loop=1
2011-11-12T20:45:18.91390Z,1321130718.9139 [transit_3km:WaypointOne](INFO): Aggregate::initialize transit_3km:WaypointOne
2011-11-12T20:45:18.91400Z,1321130718.914 [transit_3km:WaypointOne:A.Pitch] Running Loop=1
2011-11-12T20:45:18.91410Z,1321130718.9141 [transit_3km:WaypointOne:A.Pitch](DEBUG): Initialize.
2011-11-12T20:45:18.91430Z,1321130718.9143 [transit_3km:WaypointOne:B.SetSpeed] Running Loop=1
2011-11-12T20:45:18.91440Z,1321130718.9144 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Initialize.
2011-11-12T20:45:18.91460Z,1321130718.9146 [transit_3km:WaypointOne:WaypointW1.Waypoint] Running Loop=1
2011-11-12T20:45:18.91470Z,1321130718.9147 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Initialize WaypointComponent.
2011-11-12T20:45:19.31640Z,1321130719.3164 [transit_3km:WaypointOne:B.SetSpeed] Running Loop=1
2011-11-12T20:45:19.32040Z,1321130719.3204 [transit_3km:WaypointOne:A.Pitch] Running Loop=1
2011-11-12T20:45:25.33180Z,1321130725.3318 [NAL9601](INFO): Powering down
2011-11-12T20:45:36.53270Z,1321130736.5327 [Radio_Freewave](INFO): Powering down
2011-11-12T20:46:26.56980Z,1321130786.5698 [Radio_Freewave](INFO): Powering up
2011-11-12T20:46:39.42530Z,1321130799.4253 [Radio_Freewave](INFO): Powering down
2011-11-12T20:46:51.06620Z,1321130811.0662 [Radio_Freewave](INFO): Powering up
2011-11-12T20:47:56.64810Z,1321130876.6481 [Radio_Freewave](INFO): Powering down
2011-11-12T20:59:40.33140Z,1321131580.3314 [RudderServo](ERROR): getPosition uart error serial timeout
2011-11-12T20:59:40.33160Z,1321131580.3316 [RudderServo](FAULT): Rudder uart error - getPosition..serial timeout
2011-11-12T20:59:40.33170Z,1321131580.3317 [RudderServo] Communications Fault, FailCount= 1
2011-11-12T20:59:40.33170Z,1321131580.3317 [RudderServo](ERROR): Communications Fault
2011-11-12T20:59:40.35720Z,1321131580.3572 [CBIT](ERROR): Communications Fault in component: RudderServo
2011-11-12T20:59:41.19990Z,1321131581.1999 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2011-11-12T20:59:41.20000Z,1321131581.2 [RudderServo](INFO): Powering down
2011-11-12T20:59:41.22530Z,1321131581.2253 [CBIT](INFO): Clearing failed state for component RudderServo
2011-11-12T20:59:41.22540Z,1321131581.2254 [RudderServo] No Fault, FailCount= 1
2011-11-12T20:59:41.88400Z,1321131581.884 [RudderServo](DEBUG): Initializing EZServoServo.
2011-11-12T20:59:42.00420Z,1321131582.0042 [RudderServo](DEBUG): Initializing RudderServo.
2011-11-12T21:04:59.57790Z,1321131899.5779 [transit_3km:WaypointOne:WaypointW1.Waypoint](INFO): Reached Waypoint: 36.806966,-121.824326
2011-11-12T21:04:59.57820Z,1321131899.5782 [transit_3km:WaypointOne:WaypointW1.Waypoint] Stopped
2011-11-12T21:04:59.57820Z,1321131899.5782 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2011-11-12T21:04:59.57840Z,1321131899.5784 [transit_3km:WaypointOne:PHONEHOMEWPT1] Running Loop=1
2011-11-12T21:04:59.57850Z,1321131899.5785 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::initialize transit_3km:WaypointOne:PHONEHOMEWPT1
2011-11-12T21:04:59.96480Z,1321131899.9648 [transit_3km:SURFACECOMMS] Running Loop=1
2011-11-12T21:04:59.96500Z,1321131899.965 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS
2011-11-12T21:04:59.96510Z,1321131899.9651 [transit_3km:SURFACECOMMS:A.GoToSurface] Running Loop=1
2011-11-12T21:04:59.96520Z,1321131899.9652 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T21:07:44.30580Z,1321132064.3058 [Radio_Freewave](INFO): Powering up
2011-11-12T21:07:44.31730Z,1321132064.3173 [transit_3km:SURFACECOMMS:B] Running Loop=1
2011-11-12T21:07:44.31750Z,1321132064.3175 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:B
2011-11-12T21:07:44.31760Z,1321132064.3176 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1
2011-11-12T21:07:44.31770Z,1321132064.3177 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Initialize.
2011-11-12T21:07:44.31790Z,1321132064.3179 [transit_3km:SURFACECOMMS:B:B] Running Loop=1
2011-11-12T21:07:45.52850Z,1321132065.5285 [NAL9601](INFO): Powering up
2011-11-12T21:08:51.23970Z,1321132131.2397 [NAL9601](INFO): NAL9601 initialized
2011-11-12T21:08:52.31060Z,1321132132.3106 [NAL9601](IMPORTANT): GPS fix at: 1321132145
2011-11-12T21:08:52.32570Z,1321132132.3257 [transit_3km:SURFACECOMMS:B:B] Stopped
2011-11-12T21:08:52.32590Z,1321132132.3259 [transit_3km:SURFACECOMMS:B:C] Running Loop=1
2011-11-12T21:09:09.43810Z,1321132149.4381 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=37384, MT Status=1, MTMSN=3160
2011-11-12T21:09:09.59960Z,1321132149.5996 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0007.lzma
2011-11-12T21:09:09.59980Z,1321132149.5998 [NAL9601](INFO): Packets left to send: 1
2011-11-12T21:09:09.60090Z,1321132149.6009 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000015
2011-11-12T21:09:10.15100Z,1321132150.151 [NAL9601](IMPORTANT): Initialized file: Config/logger.cfg
2011-11-12T21:09:10.15230Z,1321132150.1523 [NAL9601](IMPORTANT): More data left to go, at position 90
2011-11-12T21:09:42.13780Z,1321132182.1378 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=37385, MT Status=1, MTMSN=3161
2011-11-12T21:09:42.34760Z,1321132182.3476 [NAL9601](INFO): Sent 180 bytes from file Logs/20111112T201406/shore0007.lzma
2011-11-12T21:09:42.34780Z,1321132182.3478 [NAL9601](INFO): Packets left to send: 0
2011-11-12T21:09:42.34900Z,1321132182.349 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000016
2011-11-12T21:09:42.69530Z,1321132182.6953 [NAL9601](IMPORTANT): Added data to file: Config/logger.cfg
2011-11-12T21:09:44.88490Z,1321132184.8849 [NAL9601](IMPORTANT): Success executing cat Logs/latest/4EBEDBA1.part | gunzip -f -d | cat `cp Config/.svn/text-base/logger.cfg.svn-base Config/logger.cfg` | vim -e Config/logger.cfg
2011-11-12T21:09:44.94290Z,1321132184.9429 [CommandLine](IMPORTANT): f4c2ea516ee0cfbd5cf679502b47516f  Config/logger.cfg

2011-11-12T21:09:53.22620Z,1321132193.2262 [NAL9601](INFO): SBD MO Status=0, MOMSN=37386, MT Status=0, MTMSN=0
2011-11-12T21:10:13.89470Z,1321132213.8947 [NAL9601](INFO): SBD MO Status=1, MOMSN=37387, MT Status=0, MTMSN=0
2011-11-12T21:10:14.09960Z,1321132214.0996 [NAL9601](INFO): Sent 332 bytes from file Logs/20111112T201406/shore0008.lzma
2011-11-12T21:10:14.09980Z,1321132214.0998 [NAL9601](INFO): Packets left to send: 1
2011-11-12T21:10:14.10090Z,1321132214.1009 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000017
2011-11-12T21:10:22.37800Z,1321132222.378 [NAL9601](INFO): SBD MO Status=1, MOMSN=37388, MT Status=0, MTMSN=0
2011-11-12T21:10:22.58760Z,1321132222.5876 [NAL9601](INFO): Sent 110 bytes from file Logs/20111112T201406/shore0008.lzma
2011-11-12T21:10:22.58780Z,1321132222.5878 [NAL9601](INFO): Packets left to send: 0
2011-11-12T21:10:22.58890Z,1321132222.5889 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000018
2011-11-12T21:10:29.32600Z,1321132229.326 [NAL9601](INFO): SBD MO Status=0, MOMSN=37389, MT Status=0, MTMSN=0
2011-11-12T21:10:29.49670Z,1321132229.4967 [transit_3km:SURFACECOMMS:B:C] Stopped
2011-11-12T21:10:29.49690Z,1321132229.4969 [transit_3km:SURFACECOMMS:B:D] Running Loop=1
2011-11-12T21:10:31.72350Z,1321132231.7235 [NAL9601](IMPORTANT): GPS fix at: 1321132244
2011-11-12T21:10:31.73560Z,1321132231.7356 [transit_3km:SURFACECOMMS:B:D] Stopped
2011-11-12T21:10:31.73600Z,1321132231.736 [transit_3km:SURFACECOMMS:B](INFO): Completed transit_3km:SURFACECOMMS:B
2011-11-12T21:10:31.73610Z,1321132231.7361 [transit_3km:SURFACECOMMS:B] Stopped
2011-11-12T21:10:31.73620Z,1321132231.7362 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:B
2011-11-12T21:10:31.73630Z,1321132231.7363 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Stopped
2011-11-12T21:10:31.73630Z,1321132231.7363 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T21:10:31.73680Z,1321132231.7368 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS
2011-11-12T21:10:31.73690Z,1321132231.7369 [transit_3km:SURFACECOMMS] Stopped
2011-11-12T21:10:31.73700Z,1321132231.737 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS
2011-11-12T21:10:31.73710Z,1321132231.7371 [transit_3km:SURFACECOMMS:A.GoToSurface] Stopped
2011-11-12T21:10:31.73720Z,1321132231.7372 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T21:10:32.16210Z,1321132232.1621 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Completed transit_3km:WaypointOne:PHONEHOMEWPT1
2011-11-12T21:10:32.16220Z,1321132232.1622 [transit_3km:WaypointOne:PHONEHOMEWPT1] Stopped
2011-11-12T21:10:32.16230Z,1321132232.1623 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::uninitialize transit_3km:WaypointOne:PHONEHOMEWPT1
2011-11-12T21:10:32.16310Z,1321132232.1631 [transit_3km:WaypointOne](INFO): Completed transit_3km:WaypointOne
2011-11-12T21:10:32.16320Z,1321132232.1632 [transit_3km:WaypointOne] Stopped
2011-11-12T21:10:32.16340Z,1321132232.1634 [transit_3km:WaypointOne](INFO): Aggregate::uninitialize transit_3km:WaypointOne
2011-11-12T21:10:32.16340Z,1321132232.1634 [transit_3km:WaypointOne:A.Pitch] Stopped
2011-11-12T21:10:32.16350Z,1321132232.1635 [transit_3km:WaypointOne:B.SetSpeed] Stopped
2011-11-12T21:10:32.16350Z,1321132232.1635 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Uninitialize.
2011-11-12T21:10:32.16460Z,1321132232.1646 [transit_3km](INFO): Completed transit_3km
2011-11-12T21:10:32.16470Z,1321132232.1647 [transit_3km] Stopped
2011-11-12T21:10:32.16480Z,1321132232.1648 [transit_3km](INFO): Aggregate::uninitialize transit_3km
2011-11-12T21:10:32.16490Z,1321132232.1649 [transit_3km:A.AltitudeEnvelope] Stopped
2011-11-12T21:10:32.16500Z,1321132232.165 [transit_3km:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2011-11-12T21:10:32.16500Z,1321132232.165 [transit_3km:B.DepthEnvelope] Stopped
2011-11-12T21:10:32.16510Z,1321132232.1651 [transit_3km:B.DepthEnvelope](DEBUG): Uninitialize.
2011-11-12T21:10:32.16520Z,1321132232.1652 [transit_3km:C.OffshoreEnvelope] Stopped
2011-11-12T21:10:32.16530Z,1321132232.1653 [transit_3km:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2011-11-12T21:10:32.53570Z,1321132232.5357 [MissionManager](IMPORTANT): Started mission Default
2011-11-12T21:10:32.53580Z,1321132232.5358 [Default] Running Loop=1
2011-11-12T21:10:32.53590Z,1321132232.5359 [Default](INFO): Aggregate::initialize Default
2011-11-12T21:10:32.53600Z,1321132232.536 [Default:E.SetSpeed] Running Loop=1
2011-11-12T21:10:32.53610Z,1321132232.5361 [Default:E.SetSpeed](DEBUG): Initialize.
2011-11-12T21:10:32.53620Z,1321132232.5362 [Default:F.GoToSurface] Running Loop=1
2011-11-12T21:10:32.53630Z,1321132232.5363 [Default:F.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T21:10:32.53670Z,1321132232.5367 [Default:GPS] Running Loop=1
2011-11-12T21:10:32.53680Z,1321132232.5368 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2011-11-12T21:10:32.53690Z,1321132232.5369 [Default:GPS:A.SetSpeed] Running Loop=1
2011-11-12T21:10:32.53690Z,1321132232.5369 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2011-11-12T21:10:32.53710Z,1321132232.5371 [Default:GPS:B.GoToSurface] Running Loop=1
2011-11-12T21:10:32.53720Z,1321132232.5372 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T21:10:32.53880Z,1321132232.5388 [Default:GPS:B.GoToSurface] Stopped
2011-11-12T21:10:32.53890Z,1321132232.5389 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T21:10:32.53900Z,1321132232.539 [Default:GPS:Read_GPS] Running Loop=1
2011-11-12T21:10:34.93940Z,1321132234.9394 [NAL9601](IMPORTANT): GPS fix at: 1321132247
2011-11-12T21:10:34.95200Z,1321132234.952 [Default:GPS:Read_GPS] Stopped
2011-11-12T21:10:34.95240Z,1321132234.9524 [Default:GPS](INFO): Completed Default:GPS
2011-11-12T21:10:34.95250Z,1321132234.9525 [Default:GPS] Stopped
2011-11-12T21:10:34.95260Z,1321132234.9526 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2011-11-12T21:10:34.95270Z,1321132234.9527 [Default:GPS:A.SetSpeed] Stopped
2011-11-12T21:10:34.95280Z,1321132234.9528 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T21:10:34.95290Z,1321132234.9529 [Default:Iridium] Running Loop=1
2011-11-12T21:10:34.95300Z,1321132234.953 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2011-11-12T21:10:34.95310Z,1321132234.9531 [Default:Iridium:A.SetSpeed] Running Loop=1
2011-11-12T21:10:34.95320Z,1321132234.9532 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2011-11-12T21:10:34.95330Z,1321132234.9533 [Default:Iridium:B.GoToSurface] Running Loop=1
2011-11-12T21:10:34.95340Z,1321132234.9534 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T21:10:35.34080Z,1321132235.3408 [Default:Iridium:B.GoToSurface] Stopped
2011-11-12T21:10:35.34090Z,1321132235.3409 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T21:10:35.34110Z,1321132235.3411 [Default:Iridium:Read_Iridium] Running Loop=1
2011-11-12T21:10:51.58210Z,1321132251.5821 [NAL9601](INFO): SBD MO Status=1, MOMSN=37390, MT Status=0, MTMSN=0
2011-11-12T21:10:51.74360Z,1321132251.7436 [NAL9601](INFO): Sent 221 bytes from file Logs/20111112T201406/shore0009.lzma
2011-11-12T21:10:51.74380Z,1321132251.7438 [NAL9601](INFO): Packets left to send: 0
2011-11-12T21:10:51.74490Z,1321132251.7449 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000019
2011-11-12T21:11:02.78200Z,1321132262.782 [NAL9601](INFO): SBD MO Status=0, MOMSN=37391, MT Status=0, MTMSN=0
2011-11-12T21:11:02.93560Z,1321132262.9356 [Default:Iridium:Read_Iridium] Stopped
2011-11-12T21:11:02.93600Z,1321132262.936 [Default:Iridium](INFO): Completed Default:Iridium
2011-11-12T21:11:02.93610Z,1321132262.9361 [Default:Iridium] Stopped
2011-11-12T21:11:02.93620Z,1321132262.9362 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2011-11-12T21:11:02.93630Z,1321132262.9363 [Default:Iridium:A.SetSpeed] Stopped
2011-11-12T21:11:02.93630Z,1321132262.9363 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T21:11:02.93650Z,1321132262.9365 [Default:G.Wait] Running Loop=1
2011-11-12T21:11:02.93660Z,1321132262.9366 [Default:G.Wait](DEBUG): Initialize Wait Component.
2011-11-12T21:11:13.35120Z,1321132273.3512 [NAL9601](INFO): Powering down
2011-11-12T21:16:03.36720Z,1321132563.3672 [Default:CallIridium] Running Loop=1
2011-11-12T21:16:03.36740Z,1321132563.3674 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2011-11-12T21:16:03.36760Z,1321132563.3676 [Default:CallIridium:A] Running Loop=1
2011-11-12T21:16:03.36770Z,1321132563.3677 [Default:CallIridium:A](INFO): Aggregate::initialize Default:CallIridium:A
2011-11-12T21:16:03.36780Z,1321132563.3678 [Default:CallGPS] Running Loop=1
2011-11-12T21:16:03.36790Z,1321132563.3679 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS
2011-11-12T21:16:03.36810Z,1321132563.3681 [Default:CallGPS:A] Running Loop=1
2011-11-12T21:16:03.36820Z,1321132563.3682 [Default:CallGPS:A](INFO): Aggregate::initialize Default:CallGPS:A
2011-11-12T21:16:08.36290Z,1321132568.3629 [Default:Iridium] Running Loop=1
2011-11-12T21:16:08.36310Z,1321132568.3631 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2011-11-12T21:16:08.36320Z,1321132568.3632 [Default:Iridium:A.SetSpeed] Running Loop=1
2011-11-12T21:16:08.36330Z,1321132568.3633 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2011-11-12T21:16:08.36350Z,1321132568.3635 [Default:Iridium:B.GoToSurface] Running Loop=1
2011-11-12T21:16:08.36350Z,1321132568.3635 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T21:16:08.36410Z,1321132568.3641 [Default:Iridium:B.GoToSurface] Stopped
2011-11-12T21:16:08.36420Z,1321132568.3642 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T21:16:08.36430Z,1321132568.3643 [Default:Iridium:Read_Iridium] Running Loop=1
2011-11-12T21:16:08.36460Z,1321132568.3646 [Default:GPS] Running Loop=1
2011-11-12T21:16:08.36470Z,1321132568.3647 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2011-11-12T21:16:08.36480Z,1321132568.3648 [Default:GPS:A.SetSpeed] Running Loop=1
2011-11-12T21:16:08.36490Z,1321132568.3649 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2011-11-12T21:16:08.36500Z,1321132568.365 [Default:GPS:B.GoToSurface] Running Loop=1
2011-11-12T21:16:08.36510Z,1321132568.3651 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2011-11-12T21:16:08.36570Z,1321132568.3657 [Default:GPS:B.GoToSurface] Stopped
2011-11-12T21:16:08.36580Z,1321132568.3658 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T21:16:08.36590Z,1321132568.3659 [Default:GPS:Read_GPS] Running Loop=1
2011-11-12T21:16:08.97960Z,1321132568.9796 [NAL9601](INFO): Powering up
2011-11-12T21:17:14.69170Z,1321132634.6917 [NAL9601](INFO): NAL9601 initialized
2011-11-12T21:17:37.22630Z,1321132657.2263 [NAL9601](INFO): SBD MO Status=2, MOMSN=37392, MT Status=2, MTMSN=0
2011-11-12T21:17:37.22650Z,1321132657.2265 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2011-11-12T21:18:02.75270Z,1321132682.7527 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=37392, MT Status=1, MTMSN=3162
2011-11-12T21:18:02.90360Z,1321132682.9036 [NAL9601](INFO): Sent 151 bytes from file Logs/20111112T201406/shore0010.lzma
2011-11-12T21:18:02.90380Z,1321132682.9038 [NAL9601](INFO): Packets left to send: 0
2011-11-12T21:18:02.90510Z,1321132682.9051 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000020
2011-11-12T21:18:03.32070Z,1321132683.3207 [NAL9601](INFO): Received command:restart application
2011-11-12T21:18:03.32360Z,1321132683.3236 [CommandLine](IMPORTANT): got command restart application
2011-11-12T21:18:03.34320Z,1321132683.3432 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2011-11-12T21:18:03.64560Z,1321132683.6456 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2011-11-12T21:18:03.94740Z,1321132683.9474 [controlThread](DEBUG): Uninitializing ControlThread
2011-11-12T21:18:03.94800Z,1321132683.948 [AHRS_sp3003D](INFO): Powering down
2011-11-12T21:18:04.03570Z,1321132684.0357 [AHRS_3DMGX3](INFO): Powering down
2011-11-12T21:18:04.03700Z,1321132684.037 [DVL_micro](INFO): Powering down
2011-11-12T21:18:04.03730Z,1321132684.0373 [NAL9601](INFO): Powering down
2011-11-12T21:18:04.03820Z,1321132684.0382 [DAT](INFO): Powering down
2011-11-12T21:18:04.03860Z,1321132684.0386 [WetLabsBB2FL](INFO): Powering down
2011-11-12T21:18:04.03920Z,1321132684.0392 [Bathymetry](DEBUG): Uninitialize Bathymetry Derivation.
2011-11-12T21:18:04.04100Z,1321132684.041 [Default] Stopped
2011-11-12T21:18:04.04120Z,1321132684.0412 [Default](INFO): Aggregate::uninitialize Default
2011-11-12T21:18:04.04130Z,1321132684.0413 [Default:GPS] Stopped
2011-11-12T21:18:04.04140Z,1321132684.0414 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2011-11-12T21:18:04.04140Z,1321132684.0414 [Default:GPS:A.SetSpeed] Stopped
2011-11-12T21:18:04.04150Z,1321132684.0415 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T21:18:04.04160Z,1321132684.0416 [Default:GPS:Read_GPS] Stopped
2011-11-12T21:18:04.04160Z,1321132684.0416 [Default:Iridium] Stopped
2011-11-12T21:18:04.04180Z,1321132684.0418 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2011-11-12T21:18:04.04180Z,1321132684.0418 [Default:Iridium:A.SetSpeed] Stopped
2011-11-12T21:18:04.04190Z,1321132684.0419 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2011-11-12T21:18:04.04200Z,1321132684.042 [Default:Iridium:Read_Iridium] Stopped
2011-11-12T21:18:04.04200Z,1321132684.042 [Default:CallGPS] Stopped
2011-11-12T21:18:04.04210Z,1321132684.0421 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS
2011-11-12T21:18:04.04220Z,1321132684.0422 [Default:CallGPS:A] Stopped
2011-11-12T21:18:04.04240Z,1321132684.0424 [Default:CallGPS:A](INFO): Aggregate::uninitialize Default:CallGPS:A
2011-11-12T21:18:04.04240Z,1321132684.0424 [Default:CallIridium] Stopped
2011-11-12T21:18:04.04260Z,1321132684.0426 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2011-11-12T21:18:04.04260Z,1321132684.0426 [Default:CallIridium:A] Stopped
2011-11-12T21:18:04.04270Z,1321132684.0427 [Default:CallIridium:A](INFO): Aggregate::uninitialize Default:CallIridium:A
2011-11-12T21:18:04.04280Z,1321132684.0428 [Default:E.SetSpeed] Stopped
2011-11-12T21:18:04.04290Z,1321132684.0429 [Default:E.SetSpeed](DEBUG): Uninitialize.
2011-11-12T21:18:04.04300Z,1321132684.043 [Default:F.GoToSurface] Stopped
2011-11-12T21:18:04.04300Z,1321132684.043 [Default:F.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2011-11-12T21:18:04.04320Z,1321132684.0432 [Default:G.Wait] Stopped
2011-11-12T21:18:04.04320Z,1321132684.0432 [Default:G.Wait](DEBUG): Uninitialize Wait Component.
2011-11-12T21:18:04.04750Z,1321132684.0475 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2011-11-12T21:18:04.04780Z,1321132684.0478 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2011-11-12T21:18:04.04810Z,1321132684.0481 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2011-11-12T21:18:04.04840Z,1321132684.0484 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2011-11-12T21:18:04.04880Z,1321132684.0488 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2011-11-12T21:18:04.04890Z,1321132684.0489 [BuoyancyServo](INFO): Powering down
2011-11-12T21:18:04.04940Z,1321132684.0494 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2011-11-12T21:18:04.04950Z,1321132684.0495 [ElevatorServo](INFO): Powering down
2011-11-12T21:18:04.04990Z,1321132684.0499 [MassServo](DEBUG): Uninitialize Mass Servo.
2011-11-12T21:18:04.05000Z,1321132684.05 [MassServo](INFO): Powering down
2011-11-12T21:18:04.05030Z,1321132684.0503 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2011-11-12T21:18:04.05040Z,1321132684.0504 [RudderServo](INFO): Powering down
2011-11-12T21:18:04.05070Z,1321132684.0507 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2011-11-12T21:18:04.05080Z,1321132684.0508 [ThrusterServo](INFO): Powering down
2011-11-12T21:18:04.05130Z,1321132684.0513 [SBIT](DEBUG): Uninitialize SBIT Component.
2011-11-12T21:18:04.05160Z,1321132684.0516 [IBIT](DEBUG): Uninitialize IBIT Component.
2011-11-12T21:18:04.05190Z,1321132684.0519 [CBIT](DEBUG): Uninitialize CBIT Component.
