2012-05-24T17:31:33.366Z,1337880693.366 [NAL9601](IMPORTANT): GPS fix at: 1337882686.00
2012-05-24T17:31:33.382Z,1337880693.382 [Default:GPS:Read_GPS] Stopped
2012-05-24T17:31:33.382Z,1337880693.382 [Default:GPS:D] Running Loop=1
2012-05-24T17:31:33.779Z,1337880693.779 [Default:GPS:D] Stopped
2012-05-24T17:31:33.780Z,1337880693.780 [Default:GPS](INFO): Completed Default:GPS
2012-05-24T17:31:33.780Z,1337880693.780 [Default:GPS] Stopped
2012-05-24T17:31:33.780Z,1337880693.780 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-05-24T17:31:33.780Z,1337880693.780 [Default:GPS:A.SetSpeed] Stopped
2012-05-24T17:31:33.780Z,1337880693.780 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T17:33:01.294Z,1337880781.294 [NAL9601](INFO): SBD MO Status=1, MOMSN=6804, MT Status=0, MTMSN=0
2012-05-24T17:33:01.483Z,1337880781.483 [NAL9601](INFO): Sent 332 bytes from file Logs/20120524T162113/shore0001.lzma
2012-05-24T17:33:01.483Z,1337880781.483 [NAL9601](INFO): Packets left to send: 1
2012-05-24T17:33:01.484Z,1337880781.484 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000006
2012-05-24T17:33:12.182Z,1337880792.182 [NAL9601](INFO): SBD MO Status=1, MOMSN=6805, MT Status=0, MTMSN=0
2012-05-24T17:33:12.367Z,1337880792.367 [NAL9601](INFO): Sent 176 bytes from file Logs/20120524T162113/shore0001.lzma
2012-05-24T17:33:12.367Z,1337880792.367 [NAL9601](INFO): Packets left to send: 0
2012-05-24T17:33:12.368Z,1337880792.368 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000007
2012-05-24T17:33:48.377Z,1337880828.377 [NAL9601](INFO): SBD MO Status=2, MOMSN=6806, MT Status=2, MTMSN=0
2012-05-24T17:33:48.378Z,1337880828.378 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T17:34:13.629Z,1337880853.629 [NAL9601](INFO): SBD MO Status=2, MOMSN=6806, MT Status=2, MTMSN=0
2012-05-24T17:34:13.630Z,1337880853.630 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T17:35:00.303Z,1337880900.303 [CommandLine](IMPORTANT): got command configSet VerticalControl.stopDepthExcursion 3.000000 meter
2012-05-24T17:35:00.344Z,1337880900.344 [CommandLine](IMPORTANT): got command configSet VerticalControl.buoyancyNeutral 550.000000 cubic_centimeter
2012-05-24T17:35:00.369Z,1337880900.369 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/ballast_and_trim.xml
2012-05-24T17:35:00.369Z,1337880900.369 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/ballast_and_trim.xml
2012-05-24T17:35:00.405Z,1337880900.405 [MissionManager](INFO): DefineArg ballast_and_trim.BallastDepth = 25.000000 m
2012-05-24T17:35:00.407Z,1337880900.407 [MissionManager](INFO): DefineArg ballast_and_trim.HoldDuration = 25.000000 min
2012-05-24T17:35:00.409Z,1337880900.409 [MissionManager](INFO): DefineArg ballast_and_trim.Speed = 1.000000 m/s
2012-05-24T17:35:00.411Z,1337880900.411 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 4.000000 m
2012-05-24T17:35:00.413Z,1337880900.413 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyPeriod = 0.400000 s
2012-05-24T17:35:00.415Z,1337880900.415 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyancyDefault = 0.000945 n/a
2012-05-24T17:35:00.421Z,1337880900.421 [ballast_and_trim:D.SetSpeed](DEBUG): Construct.
2012-05-24T17:35:00.424Z,1337880900.424 [ballast_and_trim:ballast:A.SetSpeed](DEBUG): Construct.
2012-05-24T17:35:00.428Z,1337880900.428 [ballast_and_trim:ballast:C.Pitch](DEBUG): Construct.
2012-05-24T17:35:00.431Z,1337880900.431 [ballast_and_trim:ballast:D.Wait](DEBUG): Construct Wait.
2012-05-24T17:35:00.436Z,1337880900.436 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Construct Wait.
2012-05-24T17:35:00.439Z,1337880900.439 [ballast_and_trim:ballast:Float_Up:A.SetSpeed](DEBUG): Construct.
2012-05-24T17:35:00.441Z,1337880900.441 [ballast_and_trim:ballast:Float_Up:B.Buoyancy](DEBUG): Construct Buoyancy.
2012-05-24T17:35:00.443Z,1337880900.443 [ballast_and_trim:ballast:Float_Up:C.Wait](DEBUG): Construct Wait.
2012-05-24T17:35:00.450Z,1337880900.450 [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-24T17:35:00.450Z,1337880900.450 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/ballast_and_trim.xml
2012-05-24T17:35:00.630Z,1337880900.630 [CommandLine](IMPORTANT): got command set ballast_and_trim.BallastDepth 5.000000 meter
2012-05-24T17:35:00.867Z,1337880900.867 [CommandLine](IMPORTANT): got command set ballast_and_trim.HoldDuration 10.000000 minute
2012-05-24T17:35:01.373Z,1337880901.373 [NAL9601](INFO): SBD MO Status=1, MOMSN=6806, MT Status=0, MTMSN=0
2012-05-24T17:35:01.499Z,1337880901.499 [NAL9601](INFO): Sent 72 bytes from file Logs/20120524T162113/shore0002.lzma
2012-05-24T17:35:01.499Z,1337880901.499 [NAL9601](INFO): Packets left to send: 0
2012-05-24T17:35:01.500Z,1337880901.500 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000008
2012-05-24T17:35:11.456Z,1337880911.456 [NAL9601](INFO): SBD MO Status=2, MOMSN=6807, MT Status=2, MTMSN=0
2012-05-24T17:35:11.457Z,1337880911.457 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T17:35:17.903Z,1337880917.903 [CommandLine](IMPORTANT): got command set ballast_and_trim.DepthDeadband 1.000000 meter
2012-05-24T17:35:26.587Z,1337880926.587 [CommandLine](IMPORTANT): got command run
2012-05-24T17:35:26.587Z,1337880926.587 [CommandLine](IMPORTANT): Running 
2012-05-24T17:35:26.951Z,1337880926.951 [Default] Stopped
2012-05-24T17:35:26.951Z,1337880926.951 [Default](INFO): Aggregate::uninitialize Default
2012-05-24T17:35:26.951Z,1337880926.951 [Default:Iridium] Stopped
2012-05-24T17:35:26.952Z,1337880926.952 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-05-24T17:35:26.952Z,1337880926.952 [Default:Iridium:A.SetSpeed] Stopped
2012-05-24T17:35:26.952Z,1337880926.952 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T17:35:26.952Z,1337880926.952 [Default:Iridium:Read_Iridium] Stopped
2012-05-24T17:35:26.952Z,1337880926.952 [Default:CallIridium] Stopped
2012-05-24T17:35:26.952Z,1337880926.952 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-05-24T17:35:26.952Z,1337880926.952 [Default:CallIridium:B] Stopped
2012-05-24T17:35:26.952Z,1337880926.952 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-05-24T17:35:26.952Z,1337880926.952 [Default:D.SetSpeed] Stopped
2012-05-24T17:35:26.952Z,1337880926.952 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-05-24T17:35:26.952Z,1337880926.953 [Default:E.GoToSurface] Stopped
2012-05-24T17:35:26.952Z,1337880926.953 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-24T17:35:26.953Z,1337880926.953 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim] Running Loop=1
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim](INFO): Aggregate::initialize ballast_and_trim
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim:A] Running Loop=1
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim:B] Running Loop=1
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim:C] Running Loop=1
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim:D.SetSpeed] Running Loop=1
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim:D.SetSpeed](DEBUG): Initialize.
2012-05-24T17:35:26.953Z,1337880926.953 [ballast_and_trim:ballast] Running Loop=1
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast](INFO): Aggregate::initialize ballast_and_trim:ballast
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast:A.SetSpeed] Running Loop=1
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast:A.SetSpeed](DEBUG): Initialize.
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast:B] Running Loop=1
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast:C.Pitch] Running Loop=1
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast:C.Pitch](DEBUG): Initialize.
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast:D.Wait] Running Loop=1
2012-05-24T17:35:26.954Z,1337880926.954 [ballast_and_trim:ballast:D.Wait](DEBUG): Initialize Wait Component.
2012-05-24T17:35:26.956Z,1337880926.956 [ballast_and_trim:ballast:C.Pitch] Running Loop=1
2012-05-24T17:35:26.956Z,1337880926.957 [ballast_and_trim:ballast:B] Running Loop=1
2012-05-24T17:35:26.957Z,1337880926.957 [ballast_and_trim:ballast:A.SetSpeed] Running Loop=1
2012-05-24T17:35:26.959Z,1337880926.958 [ballast_and_trim:D.SetSpeed] Running Loop=1
2012-05-24T17:35:26.959Z,1337880926.959 [ballast_and_trim:C] Running Loop=1
2012-05-24T17:35:26.960Z,1337880926.960 [ballast_and_trim:B] Running Loop=1
2012-05-24T17:35:26.961Z,1337880926.961 [ballast_and_trim:A] Running Loop=1
2012-05-24T17:35:32.610Z,1337880932.610 [NAL9601](INFO): Powering down
2012-05-24T17:37:29.368Z,1337881049.368 [Radio_Freewave](INFO): Powering down
2012-05-24T17:37:29.749Z,1337881049.749 [Radio_Freewave](INFO): Powering up
2012-05-24T17:37:31.349Z,1337881051.349 [Radio_Freewave](INFO): Powering down
2012-05-24T17:45:27.043Z,1337881527.043 [ballast_and_trim:ballast:D.Wait](INFO): Done Waiting.
2012-05-24T17:45:27.043Z,1337881527.043 [ballast_and_trim:ballast:D.Wait] Stopped
2012-05-24T17:45:27.043Z,1337881527.043 [ballast_and_trim:ballast:D.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T17:45:27.043Z,1337881527.043 [ballast_and_trim:ballast:ReportPositions] Running Loop=1
2012-05-24T17:45:27.043Z,1337881527.043 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:45:27.043Z,1337881527.043 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T17:45:27.451Z,1337881527.451 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 741.863158 cc Mass: -0.136908 cm Pitch: -0.025098 arcdeg 
2012-05-24T17:45:27.452Z,1337881527.452 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T17:45:27.452Z,1337881527.452 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T17:45:27.452Z,1337881527.452 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T17:46:27.857Z,1337881587.857 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T17:45:27.5Z
2012-05-24T17:46:27.857Z,1337881587.857 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T17:46:27.857Z,1337881587.857 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:46:27.858Z,1337881587.858 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:46:27.858Z,1337881587.858 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T17:46:27.858Z,1337881587.858 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T17:46:27.858Z,1337881587.858 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T17:46:27.858Z,1337881587.858 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T17:46:27.858Z,1337881587.858 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:46:27.859Z,1337881587.859 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #2
2012-05-24T17:46:27.859Z,1337881587.859 [ballast_and_trim:ballast:ReportPositions] Running Loop=2
2012-05-24T17:46:27.859Z,1337881587.859 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:46:27.859Z,1337881587.859 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T17:46:28.225Z,1337881588.225 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 741.863158 cc Mass: -0.136908 cm Pitch: -0.464551 arcdeg 
2012-05-24T17:46:28.225Z,1337881588.225 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T17:46:28.225Z,1337881588.225 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T17:46:28.225Z,1337881588.225 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T17:47:28.272Z,1337881648.272 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T17:46:28.2Z
2012-05-24T17:47:28.272Z,1337881648.272 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T17:47:28.272Z,1337881648.272 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #3
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions] Running Loop=3
2012-05-24T17:47:28.273Z,1337881648.273 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:47:28.274Z,1337881648.274 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T17:47:28.673Z,1337881648.673 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 773.826556 cc Mass: -0.155847 cm Pitch: -0.486523 arcdeg 
2012-05-24T17:47:28.673Z,1337881648.673 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T17:47:28.673Z,1337881648.673 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T17:47:28.673Z,1337881648.673 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T17:48:28.990Z,1337881708.990 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T17:47:28.7Z
2012-05-24T17:48:28.990Z,1337881708.990 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T17:48:28.990Z,1337881708.990 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:48:28.990Z,1337881708.990 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:48:28.990Z,1337881708.990 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T17:48:28.990Z,1337881708.990 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T17:48:28.991Z,1337881708.991 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T17:48:28.991Z,1337881708.991 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T17:48:28.991Z,1337881708.991 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:48:28.991Z,1337881708.991 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #4
2012-05-24T17:48:28.991Z,1337881708.991 [ballast_and_trim:ballast:ReportPositions] Running Loop=4
2012-05-24T17:48:28.991Z,1337881708.991 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:48:28.991Z,1337881708.991 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T17:48:29.329Z,1337881709.329 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 759.053510 cc Mass: -0.264895 cm Pitch: -0.266797 arcdeg 
2012-05-24T17:48:29.329Z,1337881709.329 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T17:48:29.329Z,1337881709.329 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T17:48:29.329Z,1337881709.329 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T17:49:29.553Z,1337881769.553 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T17:48:29.3Z
2012-05-24T17:49:29.554Z,1337881769.554 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T17:49:29.554Z,1337881769.554 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:49:29.554Z,1337881769.554 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:49:29.554Z,1337881769.554 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T17:49:29.554Z,1337881769.554 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T17:49:29.560Z,1337881769.560 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T17:49:29.560Z,1337881769.560 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T17:49:29.560Z,1337881769.560 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:49:29.561Z,1337881769.560 [ballast_and_trim:ballast:ReportPositions](INFO): Running loop #5
2012-05-24T17:49:29.561Z,1337881769.560 [ballast_and_trim:ballast:ReportPositions] Running Loop=5
2012-05-24T17:49:29.561Z,1337881769.561 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:49:29.561Z,1337881769.561 [ballast_and_trim:ballast:ReportPositions:A] Running Loop=1
2012-05-24T17:49:29.973Z,1337881769.973 [ballast_and_trim:ballast:ReportPositions:A](IMPORTANT): Buoyancy: 759.053510 cc Mass: -0.282657 cm Pitch: -0.025098 arcdeg 
2012-05-24T17:49:29.973Z,1337881769.973 [ballast_and_trim:ballast:ReportPositions:A] Stopped
2012-05-24T17:49:29.973Z,1337881769.973 [ballast_and_trim:ballast:ReportPositions:B.Wait] Running Loop=1
2012-05-24T17:49:29.973Z,1337881769.973 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Initialize Wait Component.
2012-05-24T17:50:30.391Z,1337881830.391 [ballast_and_trim:ballast:ReportPositions:B.Wait](INFO): Timed out from 2012-05-24T17:49:29.0Z
2012-05-24T17:50:30.391Z,1337881830.391 [ballast_and_trim:ballast:ReportPositions:A_Timeout] Running Loop=1
2012-05-24T17:50:30.391Z,1337881830.391 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Aggregate::initialize ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:50:30.392Z,1337881830.392 [ballast_and_trim:ballast:ReportPositions:A_Timeout](INFO): Completed ballast_and_trim:ballast:ReportPositions:A_Timeout
2012-05-24T17:50:30.392Z,1337881830.392 [ballast_and_trim:ballast:ReportPositions:B.Wait] Stopped
2012-05-24T17:50:30.392Z,1337881830.392 [ballast_and_trim:ballast:ReportPositions:B.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T17:50:30.392Z,1337881830.392 [ballast_and_trim:ballast:ReportPositions](INFO): Completed ballast_and_trim:ballast:ReportPositions
2012-05-24T17:50:30.392Z,1337881830.392 [ballast_and_trim:ballast:ReportPositions] Stopped
2012-05-24T17:50:30.392Z,1337881830.392 [ballast_and_trim:ballast:ReportPositions](INFO): Aggregate::uninitialize ballast_and_trim:ballast:ReportPositions
2012-05-24T17:50:30.392Z,1337881830.392 [ballast_and_trim:ballast:Float_Up] Running Loop=1
2012-05-24T17:50:30.393Z,1337881830.392 [ballast_and_trim:ballast:Float_Up](INFO): Aggregate::initialize ballast_and_trim:ballast:Float_Up
2012-05-24T17:50:30.393Z,1337881830.393 [ballast_and_trim:ballast:Float_Up:A.SetSpeed] Running Loop=1
2012-05-24T17:50:30.393Z,1337881830.393 [ballast_and_trim:ballast:Float_Up:A.SetSpeed](DEBUG): Initialize.
2012-05-24T17:50:30.393Z,1337881830.393 [ballast_and_trim:ballast:Float_Up:B.Buoyancy] Running Loop=1
2012-05-24T17:50:30.393Z,1337881830.393 [ballast_and_trim:ballast:Float_Up:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2012-05-24T17:50:30.393Z,1337881830.393 [ballast_and_trim:ballast:Float_Up:C.Wait] Running Loop=1
2012-05-24T17:50:30.393Z,1337881830.393 [ballast_and_trim:ballast:Float_Up:C.Wait](DEBUG): Initialize Wait Component.
2012-05-24T17:50:30.750Z,1337881830.750 [ballast_and_trim:ballast:Float_Up:B.Buoyancy] Running Loop=1
2012-05-24T17:50:30.751Z,1337881830.751 [ballast_and_trim:ballast:Float_Up:A.SetSpeed] Running Loop=1
2012-05-24T17:52:07.732Z,1337881927.732 [ballast_and_trim:ballast:Float_Up] Stopped
2012-05-24T17:52:07.732Z,1337881927.732 [ballast_and_trim:ballast:Float_Up](INFO): Aggregate::uninitialize ballast_and_trim:ballast:Float_Up
2012-05-24T17:52:07.733Z,1337881927.733 [ballast_and_trim:ballast:Float_Up:A.SetSpeed] Stopped
2012-05-24T17:52:07.733Z,1337881927.733 [ballast_and_trim:ballast:Float_Up:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T17:52:07.733Z,1337881927.733 [ballast_and_trim:ballast:Float_Up:B.Buoyancy] Stopped
2012-05-24T17:52:07.733Z,1337881927.733 [ballast_and_trim:ballast:Float_Up:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2012-05-24T17:52:07.733Z,1337881927.733 [ballast_and_trim:ballast:Float_Up:C.Wait] Stopped
2012-05-24T17:52:07.733Z,1337881927.733 [ballast_and_trim:ballast:Float_Up:C.Wait](DEBUG): Uninitialize Wait Component.
2012-05-24T17:52:07.734Z,1337881927.734 [ballast_and_trim:ballast](INFO): Completed ballast_and_trim:ballast
2012-05-24T17:52:07.734Z,1337881927.734 [ballast_and_trim:ballast] Stopped
2012-05-24T17:52:07.734Z,1337881927.734 [ballast_and_trim:ballast](INFO): Aggregate::uninitialize ballast_and_trim:ballast
2012-05-24T17:52:07.734Z,1337881927.734 [ballast_and_trim:ballast:A.SetSpeed] Stopped
2012-05-24T17:52:07.734Z,1337881927.734 [ballast_and_trim:ballast:A.SetSpeed](DEBUG): Uninitialize.
2012-05-24T17:52:07.734Z,1337881927.734 [ballast_and_trim:ballast:B] Stopped
2012-05-24T17:52:07.734Z,1337881927.734 [ballast_and_trim:ballast:C.Pitch] Stopped
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim](INFO): Completed ballast_and_trim
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim] Stopped
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim](INFO): Aggregate::uninitialize ballast_and_trim
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim:A] Stopped
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim:B] Stopped
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim:C] Stopped
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim:D.SetSpeed] Stopped
2012-05-24T17:52:07.736Z,1337881927.736 [ballast_and_trim:D.SetSpeed](DEBUG): Uninitialize.
2012-05-24T17:52:08.097Z,1337881928.097 [MissionManager](IMPORTANT): Started mission Default
2012-05-24T17:52:08.097Z,1337881928.097 [Default] Running Loop=1
2012-05-24T17:52:08.097Z,1337881928.097 [Default](INFO): Aggregate::initialize Default
2012-05-24T17:52:08.097Z,1337881928.097 [Default:D.SetSpeed] Running Loop=1
2012-05-24T17:52:08.097Z,1337881928.098 [Default:D.SetSpeed](DEBUG): Initialize.
2012-05-24T17:52:08.098Z,1337881928.098 [Default:E.GoToSurface] Running Loop=1
2012-05-24T17:52:08.098Z,1337881928.098 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-24T17:52:08.098Z,1337881928.098 [Default:Iridium] Running Loop=1
2012-05-24T17:52:08.102Z,1337881928.102 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-05-24T17:52:08.103Z,1337881928.103 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-05-24T17:52:08.103Z,1337881928.103 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-05-24T17:52:08.103Z,1337881928.103 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-05-24T17:52:08.103Z,1337881928.103 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-24T17:52:08.105Z,1337881928.105 [Default:CallIridium] Running Loop=1
2012-05-24T17:52:08.105Z,1337881928.105 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-05-24T17:52:08.105Z,1337881928.105 [Default:CallIridium:A] Running Loop=1
2012-05-24T17:52:08.105Z,1337881928.105 [Default:CallIridium:A] Stopped
2012-05-24T17:52:08.105Z,1337881928.105 [Default:CallIridium:B] Running Loop=1
2012-05-24T17:52:08.105Z,1337881928.105 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-05-24T17:52:08.534Z,1337881928.534 [Default:GPS] Running Loop=1
2012-05-24T17:52:08.534Z,1337881928.534 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-05-24T17:52:08.534Z,1337881928.534 [Default:GPS:A.SetSpeed] Running Loop=1
2012-05-24T17:52:08.534Z,1337881928.534 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-05-24T17:52:08.534Z,1337881928.534 [Default:GPS:B.GoToSurface] Running Loop=1
2012-05-24T17:52:08.534Z,1337881928.534 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-05-24T17:52:12.936Z,1337881932.935 [Radio_Freewave](INFO): Powering up
2012-05-24T17:52:12.946Z,1337881932.945 [Default:Iridium:B.GoToSurface] Stopped
2012-05-24T17:52:12.946Z,1337881932.946 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-24T17:52:12.946Z,1337881932.946 [Default:Iridium:Read_Iridium] Running Loop=1
2012-05-24T17:52:12.947Z,1337881932.947 [Default:GPS:B.GoToSurface] Stopped
2012-05-24T17:52:12.947Z,1337881932.947 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-05-24T17:52:12.947Z,1337881932.947 [Default:GPS:Read_GPS] Running Loop=1
2012-05-24T17:52:13.711Z,1337881933.711 [NAL9601](INFO): Powering up
2012-05-24T17:53:19.351Z,1337881999.351 [NAL9601](INFO): NAL9601 initialized
2012-05-24T17:53:48.398Z,1337882028.398 [NAL9601](INFO): SBD MO Status=2, MOMSN=6807, MT Status=2, MTMSN=0
2012-05-24T17:53:48.398Z,1337882028.398 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T17:54:33.952Z,1337882073.953 [NAL9601](INFO): SBD MO Status=2, MOMSN=6807, MT Status=2, MTMSN=0
2012-05-24T17:54:33.953Z,1337882073.953 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T17:56:15.045Z,1337882175.045 [NAL9601](INFO): SBD MO Status=2, MOMSN=6807, MT Status=2, MTMSN=0
2012-05-24T17:56:15.046Z,1337882175.046 [NAL9601](ERROR): Failed to initiate SBD session. Error code: 2
2012-05-24T17:56:53.375Z,1337882213.375 [CommandLine](IMPORTANT): got command restart logs