2012-05-24T17:58:52.449Z,1337882332.449 [NAL9601](INFO): SBD MO Status=2, MOMSN=6807, MT Status=2, MTMSN=0
2012-05-24T17:58:52.450Z,1337882332.450 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T17:59:34.865Z,1337882374.865 [NAL9601](INFO): SBD MO Status=2, MOMSN=6807, MT Status=2, MTMSN=0
2012-05-24T17:59:34.866Z,1337882374.866 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:00:28.862Z,1337882428.862 [NAL9601](INFO): SBD MO Status=1, MOMSN=6807, MT Status=0, MTMSN=0
2012-05-24T18:00:29.071Z,1337882429.071 [NAL9601](INFO): Sent 332 bytes from file Logs/20120524T165446/shore0000.lzma
2012-05-24T18:00:29.071Z,1337882429.071 [NAL9601](INFO): Packets left to send: 2
2012-05-24T18:00:29.073Z,1337882429.073 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000009
2012-05-24T18:00:44.282Z,1337882444.282 [NAL9601](INFO): SBD MO Status=2, MOMSN=6808, MT Status=2, MTMSN=0
2012-05-24T18:00:44.282Z,1337882444.282 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:01:20.218Z,1337882480.218 [NAL9601](INFO): SBD MO Status=2, MOMSN=6808, MT Status=2, MTMSN=0
2012-05-24T18:01:20.218Z,1337882480.218 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:01:58.477Z,1337882518.477 [NAL9601](INFO): SBD MO Status=1, MOMSN=6808, MT Status=0, MTMSN=0
2012-05-24T18:01:58.631Z,1337882518.631 [NAL9601](INFO): Sent 332 bytes from file Logs/20120524T165446/shore0000.lzma
2012-05-24T18:01:58.631Z,1337882518.631 [NAL9601](INFO): Packets left to send: 1
2012-05-24T18:01:58.632Z,1337882518.632 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000010
2012-05-24T18:02:11.822Z,1337882531.822 [NAL9601](INFO): SBD MO Status=2, MOMSN=6809, MT Status=2, MTMSN=0
2012-05-24T18:02:11.822Z,1337882531.822 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:02:34.463Z,1337882554.464 [NAL9601](INFO): SBD MO Status=2, MOMSN=6809, MT Status=2, MTMSN=0
2012-05-24T18:02:34.464Z,1337882554.464 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:03:43.777Z,1337882623.777 [NAL9601](INFO): SBD MO Status=2, MOMSN=6809, MT Status=2, MTMSN=0
2012-05-24T18:03:43.778Z,1337882623.778 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:03:44.571Z,1337882624.571 [NAL9601](FAULT): GPS failed to acquire within timeout.
2012-05-24T18:03:44.571Z,1337882624.571 [NAL9601] Data Fault, FailCount= 2
2012-05-24T18:03:44.571Z,1337882624.571 [NAL9601](ERROR): Data Fault
2012-05-24T18:03:44.595Z,1337882624.595 [CBIT](ERROR): Data Fault in component: NAL9601
2012-05-24T18:03:44.596Z,1337882624.596 [CBIT](CRITICAL): Data Fault in component: NAL9601
2012-05-24T18:03:44.991Z,1337882624.991 [NAL9601](INFO): Powering down
2012-05-24T18:04:58.207Z,1337882698.207 [CommandLine](IMPORTANT): got command configSet VerticalControl.buoyancyNeutral 350.000000 cubic_centimeter
2012-05-24T18:04:58.243Z,1337882698.243 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/ballast_and_trim.xml
2012-05-24T18:04:58.244Z,1337882698.244 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/ballast_and_trim.xml
2012-05-24T18:04:58.286Z,1337882698.286 [MissionManager](INFO): DefineArg ballast_and_trim.BallastDepth = 25.000000 m
2012-05-24T18:04:58.288Z,1337882698.288 [MissionManager](INFO): DefineArg ballast_and_trim.HoldDuration = 25.000000 min
2012-05-24T18:04:58.290Z,1337882698.290 [MissionManager](INFO): DefineArg ballast_and_trim.Speed = 1.000000 m/s
2012-05-24T18:04:58.292Z,1337882698.292 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 4.000000 m
2012-05-24T18:04:58.294Z,1337882698.294 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyPeriod = 0.400000 s
2012-05-24T18:04:58.297Z,1337882698.297 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyancyDefault = 0.000945 n/a
2012-05-24T18:04:58.302Z,1337882698.302 [ballast_and_trim:D.SetSpeed](DEBUG): Construct.
2012-05-24T18:04:58.306Z,1337882698.306 [ballast_and_trim:ballast:A.SetSpeed](DEBUG): Construct.
2012-05-24T18:04:58.309Z,1337882698.309 [ballast_and_trim:ballast:C.Pitch](DEBUG): Construct.
2012-05-24T18:04:58.313Z,1337882698.313 [ballast_and_trim:ballast:D.Wait](DEBUG): Construct Wait.
2012-05-24T18:04:58.317Z,1337882698.317 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Construct Wait.
2012-05-24T18:04:58.320Z,1337882698.320 [ballast_and_trim:ballast:Float_Up:A.SetSpeed](DEBUG): Construct.
2012-05-24T18:04:58.323Z,1337882698.323 [ballast_and_trim:ballast:Float_Up:B.Buoyancy](DEBUG): Construct Buoyancy.
2012-05-24T18:04:58.325Z,1337882698.325 [ballast_and_trim:ballast:Float_Up:C.Wait](DEBUG): Construct Wait.
2012-05-24T18:04:58.330Z,1337882698.330 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Trigger="Tethys/Trigger" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Trigger http://aosn.mbari.org/tethys/Xml/Trigger.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="ballast_and_trim">

<!-- The following arguments are input arguments -->

    <DefineArg Name="BallastDepth"><Units:meter/><Value>25.0</Value></DefineArg>

    <DefineArg Name="HoldDuration"><Units:minute/><Value>25</Value></DefineArg>

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

    <DefineArg Name="DepthDeadband"><Units:meter/><Value>4.0</Value></DefineArg>

    <DefineArg Name="BuoyPeriod"><Units:second/><Value>0.4</Value></DefineArg>

    <DefineArg Name="BuoyancyDefault"><Control:VerticalControl.buoyancyDefault/></DefineArg>

<!-- The timeout -->

    <Timeout Duration="P90M"/>

<!-- And now the mission -->

    <Assign RunIn="Parallel"><Control:VerticalControl.kpPitchMass/><Units:count/><Value>0.01</Value></Assign>

    <Assign RunIn="Parallel"><Control:VerticalControl.kiPitchMass/><Units:reciprocal_second/><Value>0.0015</Value></Assign>

    <Assign RunIn="Parallel"><Control:VerticalControl.kdPitchMass/><Units:second/><Value>0</Value></Assign>

<!--    <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>52</Value></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:OffshoreEnvelope RunIn="Parallel">
        <Setting><Guidance:OffshoreEnvelope.minOffshore/><Units:kilometer/><Value>2.0</Value></Setting>
        <Setting><Guidance:OffshoreEnvelope.maxOffshore/><Units:kilometer/><Value>30.0</Value></Setting>
    </Guidance:OffshoreEnvelope>
-->
    <!-- <Insert Filename="Insert/Surface.xml" Id="SurfaceComms" /> -->

    <Guidance:SetSpeed>
        <While><Universal:platform_propeller_rotation_rate/>
            <Eq><Units:radian_per_second/><Value>0</Value></Eq>
        </While>
        <Setting><Guidance:SetSpeed.period/><Arg Name="BuoyPeriod"/></Setting>
    </Guidance:SetSpeed>

    <Aggregate Id="ballast">

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

        <Assign RunIn="Parallel"><Control:VerticalControl.depthDeadband/><Arg Name="DepthDeadband"/></Assign>

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

        <Guidance:Wait RunIn="Sequence">
            <Setting><Guidance:Wait.duration/><Arg Name="HoldDuration"/></Setting>
        </Guidance:Wait>

        <Aggregate Id="ReportPositions" Repeat="5" >

            <Syslog Severity="Important">
            Buoyancy:<Universal:platform_buoyancy_position/><Units:cubic_centimeter/>
            Mass:<Universal:platform_mass_position/><Units:centimeter/>
            Pitch:<Universal:platform_pitch_angle/><Units:degree/>
            </Syslog>

            <Guidance:Wait RunIn="Sequence">
                <Timeout Duration="P1M"></Timeout>
            </Guidance:Wait>

        </Aggregate>

        <Aggregate Id="Float_Up">

            <Until><Universal:depth/>
                <Lt><Units:meter/><Value>1</Value></Lt>
            </Until>

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

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

            <Guidance:Wait RunIn="Sequence">
                <Timeout Duration="P15M"></Timeout>
            </Guidance:Wait>

        </Aggregate>

    </Aggregate>

</Mission>


2012-05-24T18:04:58.331Z,1337882698.331 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/ballast_and_trim.xml
2012-05-24T18:04:58.662Z,1337882698.662 [CommandLine](IMPORTANT): got command set ballast_and_trim.BallastDepth 5.000000 meter
2012-05-24T18:04:58.967Z,1337882698.967 [CommandLine](IMPORTANT): got command set ballast_and_trim.HoldDuration 10.000000 minute
2012-05-24T18:05:03.323Z,1337882703.323 [CommandLine](IMPORTANT): got command set ballast_and_trim.DepthDeadband 1.000000 meter
2012-05-24T18:05:08.339Z,1337882708.339 [CommandLine](IMPORTANT): got command run
2012-05-24T18:05:08.339Z,1337882708.339 [CommandLine](IMPORTANT): Running 
2012-05-24T18:05:08.553Z,1337882708.553 [Default] Stopped
2012-05-24T18:05:08.553Z,1337882708.553 [Default](INFO): Aggregate::uninitialize Default
2012-05-24T18:05:08.553Z,1337882708.553 [Default:GPS] Stopped
2012-05-24T18:05:08.553Z,1337882708.553 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-05-24T18:05:08.553Z,1337882708.553 [Default:GPS:A.SetSpeed] Stopped
2012-05-24T18:05:08.553Z,1337882708.553 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T18:05:08.553Z,1337882708.553 [Default:GPS:Read_GPS] Stopped
2012-05-24T18:05:08.553Z,1337882708.553 [Default:Iridium] Stopped
2012-05-24T18:05:08.553Z,1337882708.553 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-05-24T18:05:08.553Z,1337882708.553 [Default:Iridium:A.SetSpeed] Stopped
2012-05-24T18:05:08.553Z,1337882708.553 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T18:05:08.554Z,1337882708.554 [Default:Iridium:Read_Iridium] Stopped
2012-05-24T18:05:08.554Z,1337882708.554 [Default:CallIridium] Stopped
2012-05-24T18:05:08.554Z,1337882708.554 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-05-24T18:05:08.554Z,1337882708.554 [Default:CallIridium:B] Stopped
2012-05-24T18:05:08.554Z,1337882708.554 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-05-24T18:05:08.554Z,1337882708.554 [Default:D.SetSpeed] Stopped
2012-05-24T18:05:08.554Z,1337882708.554 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-05-24T18:05:08.554Z,1337882708.554 [Default:E.GoToSurface] Stopped
2012-05-24T18:05:08.554Z,1337882708.554 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-24T18:05:08.554Z,1337882708.555 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim] Running Loop=1
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim](INFO): Aggregate::initialize ballast_and_trim
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim:A] Running Loop=1
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim:B] Running Loop=1
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim:C] Running Loop=1
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim:D.SetSpeed] Running Loop=1
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim:D.SetSpeed](DEBUG): Initialize.
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim:ballast] Running Loop=1
2012-05-24T18:05:08.555Z,1337882708.555 [ballast_and_trim:ballast](INFO): Aggregate::initialize ballast_and_trim:ballast
2012-05-24T18:05:08.555Z,1337882708.556 [ballast_and_trim:ballast:A.SetSpeed] Running Loop=1
2012-05-24T18:05:08.555Z,1337882708.556 [ballast_and_trim:ballast:A.SetSpeed](DEBUG): Initialize.
2012-05-24T18:05:08.556Z,1337882708.556 [ballast_and_trim:ballast:B] Running Loop=1
2012-05-24T18:05:08.556Z,1337882708.556 [ballast_and_trim:ballast:C.Pitch] Running Loop=1
2012-05-24T18:05:08.556Z,1337882708.556 [ballast_and_trim:ballast:C.Pitch](DEBUG): Initialize.
2012-05-24T18:05:08.556Z,1337882708.556 [ballast_and_trim:ballast:D.Wait] Running Loop=1
2012-05-24T18:05:08.556Z,1337882708.556 [ballast_and_trim:ballast:D.Wait](DEBUG): Initialize Wait Component.
2012-05-24T18:05:08.557Z,1337882708.557 [ballast_and_trim:ballast:C.Pitch] Running Loop=1
2012-05-24T18:05:08.558Z,1337882708.558 [ballast_and_trim:ballast:B] Running Loop=1
2012-05-24T18:05:08.559Z,1337882708.559 [ballast_and_trim:ballast:A.SetSpeed] Running Loop=1
2012-05-24T18:05:08.560Z,1337882708.560 [ballast_and_trim:D.SetSpeed] Running Loop=1
2012-05-24T18:05:08.561Z,1337882708.561 [ballast_and_trim:C] Running Loop=1
2012-05-24T18:05:08.562Z,1337882708.562 [ballast_and_trim:B] Running Loop=1
2012-05-24T18:05:08.563Z,1337882708.563 [ballast_and_trim:A] Running Loop=1
2012-05-24T18:05:44.711Z,1337882744.711 [CBIT](INFO): Clearing failed count for component NAL9601
2012-05-24T18:05:44.711Z,1337882744.711 [NAL9601] No Fault, FailCount= 2
2012-05-24T18:05:45.065Z,1337882745.065 [NAL9601](INFO): Powering up NAL9601
2012-05-24T18:06:50.803Z,1337882810.803 [NAL9601](INFO): NAL9601 initialized
2012-05-24T18:06:56.750Z,1337882816.750 [NAL9601](INFO): Powering down
2012-05-24T18:07:11.417Z,1337882831.417 [Radio_Freewave](INFO): Powering down
2012-05-24T18:07:11.789Z,1337882831.789 [Radio_Freewave](INFO): Powering up
2012-05-24T18:07:13.397Z,1337882833.397 [Radio_Freewave](INFO): Powering down
2012-05-24T18:07:13.789Z,1337882833.789 [Radio_Freewave](INFO): Powering up
2012-05-24T18:07:15.386Z,1337882835.386 [Radio_Freewave](INFO): Powering down
2012-05-24T18:15:09.028Z,1337883309.028 [ballast_and_trim:ballast:D.Wait](INFO): Done Waiting.
2012-05-24T18:15:09.028Z,1337883309.028 [ballast_and_trim:ballast:D.Wait] Stopped
2012-05-24T18:15:09.028Z,1337883309.028 [ballast_and_trim:ballast:D.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T18:15:09.028Z,1337883309.028 [ballast_and_trim:ballast:ReportPositions] Running Loop=1
2012-05-24T18:15:09.028Z,1337883309.028 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:15:09.029Z,1337883309.029 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T18:15:09.480Z,1337883309.480 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 857.629755 cc Mass: -0.365426 cm Pitch: -0.904004 arcdeg 
2012-05-24T18:15:09.481Z,1337883309.481 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T18:15:09.481Z,1337883309.481 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T18:15:09.481Z,1337883309.481 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T18:16:09.501Z,1337883369.501 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T18:15:09.5Z
2012-05-24T18:16:09.501Z,1337883369.501 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T18:16:09.501Z,1337883369.501 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:16:09.501Z,1337883369.501 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:16:09.501Z,1337883369.501 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T18:16:09.501Z,1337883369.501 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T18:16:09.502Z,1337883369.502 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T18:16:09.502Z,1337883369.502 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T18:16:09.502Z,1337883369.502 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:16:09.502Z,1337883369.502 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #2
2012-05-24T18:16:09.502Z,1337883369.502 [ballast_and_trim:ballast:ReportPositions] Running Loop=2
2012-05-24T18:16:09.502Z,1337883369.502 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:16:09.502Z,1337883369.503 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T18:16:09.901Z,1337883369.901 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 726.552913 cc Mass: -0.291579 cm Pitch: 1.842578 arcdeg 
2012-05-24T18:16:09.901Z,1337883369.901 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T18:16:09.901Z,1337883369.901 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T18:16:09.901Z,1337883369.901 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T18:17:10.193Z,1337883430.193 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T18:16:09.9Z
2012-05-24T18:17:10.193Z,1337883430.193 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T18:17:10.193Z,1337883430.193 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:17:10.193Z,1337883430.193 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:17:10.193Z,1337883430.193 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T18:17:10.193Z,1337883430.193 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T18:17:10.193Z,1337883430.194 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T18:17:10.194Z,1337883430.194 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T18:17:10.194Z,1337883430.194 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:17:10.194Z,1337883430.194 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #3
2012-05-24T18:17:10.194Z,1337883430.194 [ballast_and_trim:ballast:ReportPositions] Running Loop=3
2012-05-24T18:17:10.194Z,1337883430.194 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:17:10.194Z,1337883430.194 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T18:17:10.593Z,1337883430.593 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 788.868172 cc Mass: -0.167323 cm Pitch: -1.189648 arcdeg 
2012-05-24T18:17:10.593Z,1337883430.593 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T18:17:10.593Z,1337883430.593 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T18:17:10.594Z,1337883430.593 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T18:18:10.628Z,1337883490.628 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T18:17:10.6Z
2012-05-24T18:18:10.628Z,1337883490.628 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T18:18:10.628Z,1337883490.628 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:18:10.628Z,1337883490.628 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #4
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions] Running Loop=4
2012-05-24T18:18:10.629Z,1337883490.629 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:18:10.630Z,1337883490.630 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T18:18:11.032Z,1337883491.032 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 789.002457 cc Mass: -0.353869 cm Pitch: 0.238574 arcdeg 
2012-05-24T18:18:11.032Z,1337883491.032 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T18:18:11.032Z,1337883491.032 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T18:18:11.032Z,1337883491.032 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T18:19:11.255Z,1337883551.255 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T18:18:11.0Z
2012-05-24T18:19:11.255Z,1337883551.255 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T18:19:11.255Z,1337883551.255 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:19:11.255Z,1337883551.255 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:19:11.255Z,1337883551.255 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T18:19:11.255Z,1337883551.255 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T18:19:11.255Z,1337883551.255 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T18:19:11.255Z,1337883551.256 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T18:19:11.256Z,1337883551.256 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:19:11.256Z,1337883551.256 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #5
2012-05-24T18:19:11.256Z,1337883551.256 [ballast_and_trim:ballast:ReportPositions] Running Loop=5
2012-05-24T18:19:11.256Z,1337883551.256 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:19:11.256Z,1337883551.256 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T18:19:11.633Z,1337883551.633 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 730.984844 cc Mass: -0.196643 cm Pitch: 0.963672 arcdeg 
2012-05-24T18:19:11.634Z,1337883551.634 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T18:19:11.634Z,1337883551.634 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T18:19:11.634Z,1337883551.634 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T18:20:11.653Z,1337883611.653 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T18:19:11.6Z
2012-05-24T18:20:11.653Z,1337883611.653 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T18:20:11.653Z,1337883611.653 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:20:11.653Z,1337883611.653 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T18:20:11.653Z,1337883611.653 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T18:20:11.653Z,1337883611.653 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:Float_Up] Running Loop=1
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:Float_Up](INFO): Aggregate::initialize ballast_and_trim:ballast:Float_Up
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:Float_Up:A.SetSpeed] Running Loop=1
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:Float_Up:A.SetSpeed](DEBUG): Initialize.
2012-05-24T18:20:11.654Z,1337883611.654 [ballast_and_trim:ballast:Float_Up:B.Buoyancy] Running Loop=1
2012-05-24T18:20:11.655Z,1337883611.655 [ballast_and_trim:ballast:Float_Up:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2012-05-24T18:20:11.655Z,1337883611.655 [ballast_and_trim:ballast:Float_Up:C.Wait] Running Loop=1
2012-05-24T18:20:11.655Z,1337883611.655 [ballast_and_trim:ballast:Float_Up:C.Wait](DEBUG): Initialize Wait Component.
2012-05-24T18:20:12.058Z,1337883612.058 [ballast_and_trim:ballast:Float_Up:B.Buoyancy] Running Loop=1
2012-05-24T18:20:12.058Z,1337883612.059 [ballast_and_trim:ballast:Float_Up:A.SetSpeed] Running Loop=1
2012-05-24T18:22:08.269Z,1337883728.269 [ballast_and_trim:ballast:Float_Up] Stopped
2012-05-24T18:22:08.269Z,1337883728.269 [ballast_and_trim:ballast:Float_Up](INFO): Aggregate::uninitialize ballast_and_trim:ballast:Float_Up
2012-05-24T18:22:08.269Z,1337883728.269 [ballast_and_trim:ballast:Float_Up:A.SetSpeed] Stopped
2012-05-24T18:22:08.269Z,1337883728.270 [ballast_and_trim:ballast:Float_Up:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T18:22:08.269Z,1337883728.270 [ballast_and_trim:ballast:Float_Up:B.Buoyancy] Stopped
2012-05-24T18:22:08.270Z,1337883728.270 [ballast_and_trim:ballast:Float_Up:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2012-05-24T18:22:08.270Z,1337883728.270 [ballast_and_trim:ballast:Float_Up:C.Wait] Stopped
2012-05-24T18:22:08.270Z,1337883728.270 [ballast_and_trim:ballast:Float_Up:C.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T18:22:08.271Z,1337883728.271 [ballast_and_trim:ballast](INFO): Completed ballast_and_trim:ballast
2012-05-24T18:22:08.271Z,1337883728.271 [ballast_and_trim:ballast] Stopped
2012-05-24T18:22:08.271Z,1337883728.271 [ballast_and_trim:ballast](INFO): Aggregate::uninitialize ballast_and_trim:ballast
2012-05-24T18:22:08.271Z,1337883728.271 [ballast_and_trim:ballast:A.SetSpeed] Stopped
2012-05-24T18:22:08.271Z,1337883728.272 [ballast_and_trim:ballast:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T18:22:08.272Z,1337883728.272 [ballast_and_trim:ballast:B] Stopped
2012-05-24T18:22:08.272Z,1337883728.272 [ballast_and_trim:ballast:C.Pitch] Stopped
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim](INFO): Completed ballast_and_trim
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim] Stopped
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim](INFO): Aggregate::uninitialize ballast_and_trim
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim:A] Stopped
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim:B] Stopped
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim:C] Stopped
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim:D.SetSpeed] Stopped
2012-05-24T18:22:08.273Z,1337883728.273 [ballast_and_trim:D.SetSpeed](DEBUG): Uninitialize.
2012-05-24T18:22:08.664Z,1337883728.664 [MissionManager](IMPORTANT): Started mission Default
2012-05-24T18:22:08.664Z,1337883728.664 [Default] Running Loop=1
2012-05-24T18:22:08.664Z,1337883728.664 [Default](INFO): Aggregate::initialize Default
2012-05-24T18:22:08.664Z,1337883728.664 [Default:D.SetSpeed] Running Loop=1
2012-05-24T18:22:08.664Z,1337883728.664 [Default:D.SetSpeed](DEBUG): Initialize.
2012-05-24T18:22:08.664Z,1337883728.664 [Default:E.GoToSurface] Running Loop=1
2012-05-24T18:22:08.664Z,1337883728.664 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-24T18:22:08.664Z,1337883728.664 [Default:Iridium] Running Loop=1
2012-05-24T18:22:08.665Z,1337883728.665 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-05-24T18:22:08.665Z,1337883728.665 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-05-24T18:22:08.665Z,1337883728.665 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-05-24T18:22:08.665Z,1337883728.665 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-05-24T18:22:08.665Z,1337883728.665 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-24T18:22:08.667Z,1337883728.667 [Default:CallIridium] Running Loop=1
2012-05-24T18:22:08.667Z,1337883728.667 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-05-24T18:22:08.667Z,1337883728.667 [Default:CallIridium:A] Running Loop=1
2012-05-24T18:22:08.667Z,1337883728.667 [Default:CallIridium:A] Stopped
2012-05-24T18:22:08.667Z,1337883728.667 [Default:CallIridium:B] Running Loop=1
2012-05-24T18:22:08.668Z,1337883728.668 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-05-24T18:22:08.668Z,1337883728.668 [Default:GPS] Running Loop=1
2012-05-24T18:22:08.669Z,1337883728.669 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-05-24T18:22:08.669Z,1337883728.669 [Default:GPS:A.SetSpeed] Running Loop=1
2012-05-24T18:22:08.669Z,1337883728.669 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-05-24T18:22:08.669Z,1337883728.669 [Default:GPS:B.GoToSurface] Running Loop=1
2012-05-24T18:22:08.669Z,1337883728.669 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-24T18:22:15.413Z,1337883735.413 [Radio_Freewave](INFO): Powering up
2012-05-24T18:22:15.423Z,1337883735.423 [Default:Iridium:B.GoToSurface] Stopped
2012-05-24T18:22:15.423Z,1337883735.423 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-24T18:22:15.423Z,1337883735.423 [Default:Iridium:Read_Iridium] Running Loop=1
2012-05-24T18:22:15.424Z,1337883735.424 [Default:GPS:B.GoToSurface] Stopped
2012-05-24T18:22:15.424Z,1337883735.424 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-24T18:22:15.424Z,1337883735.424 [Default:GPS:Read_GPS] Running Loop=1
2012-05-24T18:22:16.241Z,1337883736.241 [NAL9601](INFO): Powering up
2012-05-24T18:23:21.879Z,1337883801.879 [NAL9601](INFO): NAL9601 initialized
2012-05-24T18:23:48.536Z,1337883828.536 [NAL9601](INFO): SBD MO Status=1, MOMSN=6809, MT Status=0, MTMSN=0
2012-05-24T18:23:48.727Z,1337883828.727 [NAL9601](INFO): Sent 126 bytes from file Logs/20120524T165446/shore0000.lzma
2012-05-24T18:23:48.727Z,1337883828.727 [NAL9601](INFO): Packets left to send: 0
2012-05-24T18:23:48.728Z,1337883828.728 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000011
2012-05-24T18:23:59.546Z,1337883839.546 [NAL9601](INFO): SBD MO Status=2, MOMSN=6810, MT Status=2, MTMSN=0
2012-05-24T18:23:59.546Z,1337883839.546 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:24:23.087Z,1337883863.087 [NAL9601](INFO): SBD MO Status=2, MOMSN=6810, MT Status=2, MTMSN=0
2012-05-24T18:24:23.088Z,1337883863.088 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:24:59.994Z,1337883899.994 [NAL9601](INFO): SBD MO Status=1, MOMSN=6810, MT Status=0, MTMSN=0
2012-05-24T18:25:00.115Z,1337883900.115 [NAL9601](INFO): Sent 332 bytes from file Logs/20120524T173012/shore0000.lzma
2012-05-24T18:25:00.115Z,1337883900.115 [NAL9601](INFO): Packets left to send: 3
2012-05-24T18:25:00.116Z,1337883900.116 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000012
2012-05-24T18:25:10.182Z,1337883910.182 [NAL9601](INFO): SBD MO Status=2, MOMSN=6811, MT Status=2, MTMSN=0
2012-05-24T18:25:10.183Z,1337883910.182 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:25:38.105Z,1337883938.105 [NAL9601](INFO): SBD MO Status=1, MOMSN=6811, MT Status=0, MTMSN=0
2012-05-24T18:25:38.259Z,1337883938.259 [NAL9601](INFO): Sent 332 bytes from file Logs/20120524T173012/shore0000.lzma
2012-05-24T18:25:38.259Z,1337883938.259 [NAL9601](INFO): Packets left to send: 2
2012-05-24T18:25:38.260Z,1337883938.260 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000013
2012-05-24T18:25:46.691Z,1337883946.691 [NAL9601](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0
2012-05-24T18:25:46.691Z,1337883946.691 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:26:11.400Z,1337883971.401 [NAL9601](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0
2012-05-24T18:26:11.401Z,1337883971.401 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:26:35.723Z,1337883995.723 [NAL9601](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0
2012-05-24T18:26:35.723Z,1337883995.723 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:27:11.196Z,1337884031.196 [NAL9601](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0
2012-05-24T18:27:11.196Z,1337884031.196 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:27:31.965Z,1337884051.965 [NAL9601](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0
2012-05-24T18:27:31.966Z,1337884051.966 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:27:46.416Z,1337884066.416 [NAL9601](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0
2012-05-24T18:27:46.416Z,1337884066.416 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T18:28:05.379Z,1337884085.379 [CommandLine](IMPORTANT): got command restart logs