2013-01-29T19:46:20.814Z,1359488780.814 [Supervisor](DEBUG): Initializing supervisor.
2013-01-29T19:46:20.817Z,1359488780.817 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-01-29T19:46:20.817Z,1359488780.818 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-01-29T19:46:20.818Z,1359488780.819 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-01-29T19:46:20.822Z,1359488780.822 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-01-29T19:46:20.833Z,1359488780.833 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-01-29T19:46:20.834Z,1359488780.834 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-01-29T19:46:20.835Z,1359488780.835 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-01-29T19:46:20.836Z,1359488780.836 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-01-29T19:46:20.837Z,1359488780.837 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-01-29T19:46:20.838Z,1359488780.838 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-01-29T19:46:21.161Z,1359488781.161 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-01-29T19:46:21.162Z,1359488781.162 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-01-29T19:46:21.342Z,1359488781.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-01-29T19:46:21.343Z,1359488781.342 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-01-29T19:46:21.421Z,1359488781.421 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-01-29T19:46:21.421Z,1359488781.421 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-01-29T19:46:21.609Z,1359488781.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-01-29T19:46:21.610Z,1359488781.610 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-01-29T19:46:21.736Z,1359488781.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-01-29T19:46:21.736Z,1359488781.736 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-01-29T19:46:21.960Z,1359488781.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-01-29T19:46:21.961Z,1359488781.961 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-01-29T19:46:22.124Z,1359488782.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-01-29T19:46:22.124Z,1359488782.124 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-01-29T19:46:22.368Z,1359488782.368 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-01-29T19:46:22.368Z,1359488782.368 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-01-29T19:46:22.460Z,1359488782.460 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-01-29T19:46:22.460Z,1359488782.460 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-01-29T19:46:22.851Z,1359488782.851 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-01-29T19:46:22.851Z,1359488782.851 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-01-29T19:46:22.959Z,1359488782.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-01-29T19:46:22.960Z,1359488782.960 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-01-29T19:46:23.039Z,1359488783.039 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-01-29T19:46:23.040Z,1359488783.040 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-01-29T19:46:23.135Z,1359488783.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-01-29T19:46:23.260Z,1359488783.260 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-01-29T19:46:23.340Z,1359488783.340 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-01-29T19:46:23.434Z,1359488783.434 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-01-29T19:46:23.528Z,1359488783.528 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-01-29T19:46:23.640Z,1359488783.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-01-29T19:46:23.726Z,1359488783.726 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-01-29T19:46:23.807Z,1359488783.807 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-01-29T19:46:23.839Z,1359488783.839 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-01-29T19:46:23.992Z,1359488783.992 [InternalSim] Loaded
2013-01-29T19:46:23.992Z,1359488783.992 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-01-29T19:46:23.993Z,1359488783.993 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-01-29T19:46:23.993Z,1359488783.993 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-01-29T19:46:24.049Z,1359488784.049 [SBIT](DEBUG): Construct Startup Built In Test.
2013-01-29T19:46:24.078Z,1359488784.078 [SBIT] Loaded
2013-01-29T19:46:24.079Z,1359488784.079 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-01-29T19:46:24.079Z,1359488784.079 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-01-29T19:46:24.109Z,1359488784.109 [IBIT] Loaded
2013-01-29T19:46:24.109Z,1359488784.109 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-01-29T19:46:24.113Z,1359488784.113 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-01-29T19:46:24.233Z,1359488784.233 [CBIT] Loaded
2013-01-29T19:46:24.233Z,1359488784.233 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-01-29T19:46:24.233Z,1359488784.233 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-01-29T19:46:24.234Z,1359488784.234 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-01-29T19:46:24.384Z,1359488784.384 [BuoyancyServo] Loaded
2013-01-29T19:46:24.384Z,1359488784.384 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-01-29T19:46:24.397Z,1359488784.397 [ElevatorServo] Loaded
2013-01-29T19:46:24.397Z,1359488784.397 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-01-29T19:46:24.409Z,1359488784.409 [MassServo] Loaded
2013-01-29T19:46:24.409Z,1359488784.409 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-01-29T19:46:24.421Z,1359488784.421 [RudderServo] Loaded
2013-01-29T19:46:24.422Z,1359488784.422 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-01-29T19:46:24.434Z,1359488784.434 [ThrusterServo] Loaded
2013-01-29T19:46:24.434Z,1359488784.434 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-01-29T19:46:24.435Z,1359488784.434 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-01-29T19:46:24.435Z,1359488784.435 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-01-29T19:46:24.452Z,1359488784.452 [DepthRateCalculator] Loaded
2013-01-29T19:46:24.452Z,1359488784.452 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-01-29T19:46:27.798Z,1359488787.798 [HFRadarModelCalc] Loaded
2013-01-29T19:46:27.798Z,1359488787.798 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-01-29T19:46:27.814Z,1359488787.814 [NavChart] Loaded
2013-01-29T19:46:27.815Z,1359488787.815 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-01-29T19:46:27.821Z,1359488787.820 [PitchRateCalculator] Loaded
2013-01-29T19:46:27.821Z,1359488787.821 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-01-29T19:46:27.827Z,1359488787.827 [SpeedCalculator] Loaded
2013-01-29T19:46:27.828Z,1359488787.828 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-01-29T19:46:27.842Z,1359488787.842 [TempGradientCalculator] Loaded
2013-01-29T19:46:27.843Z,1359488787.843 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-01-29T19:46:27.849Z,1359488787.849 [YawRateCalculator] Loaded
2013-01-29T19:46:27.849Z,1359488787.849 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-01-29T19:46:27.890Z,1359488787.890 [Navigation] Loaded
2013-01-29T19:46:27.890Z,1359488787.890 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-01-29T19:46:27.891Z,1359488787.891 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-01-29T19:46:27.891Z,1359488787.891 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-01-29T19:46:28.112Z,1359488788.112 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-01-29T19:46:28.112Z,1359488788.112 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-01-29T19:46:28.134Z,1359488788.134 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-01-29T19:46:28.134Z,1359488788.134 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-01-29T19:46:28.173Z,1359488788.173 [VerticalControl](DEBUG): Construct VerticalControl.
2013-01-29T19:46:28.268Z,1359488788.268 [VerticalControl] Loaded
2013-01-29T19:46:28.269Z,1359488788.269 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-01-29T19:46:28.270Z,1359488788.270 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-01-29T19:46:28.327Z,1359488788.327 [HorizontalControl] Loaded
2013-01-29T19:46:28.327Z,1359488788.327 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-01-29T19:46:28.328Z,1359488788.328 [SpeedControl](DEBUG): Construct SpeedControl.
2013-01-29T19:46:28.330Z,1359488788.330 [SpeedControl] Loaded
2013-01-29T19:46:28.330Z,1359488788.330 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-01-29T19:46:28.331Z,1359488788.331 [LoopControl](DEBUG): Construct LoopControl.
2013-01-29T19:46:28.331Z,1359488788.332 [LoopControl] Loaded
2013-01-29T19:46:28.332Z,1359488788.332 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-01-29T19:46:28.332Z,1359488788.332 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-01-29T19:46:28.333Z,1359488788.333 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-01-29T19:46:28.338Z,1359488788.338 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-01-29T19:46:28.343Z,1359488788.343 [AsyncPiEstimator] Loaded
2013-01-29T19:46:28.343Z,1359488788.343 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-01-29T19:46:28.344Z,1359488788.344 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A34E0
2013-01-29T19:46:28.345Z,1359488788.345 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-01-29T19:46:28.345Z,1359488788.345 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-01-29T19:46:28.473Z,1359488788.473 [AHRS_sp3003D] Loaded
2013-01-29T19:46:28.473Z,1359488788.473 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-01-29T19:46:28.734Z,1359488788.734 [Batt_Ocean_Server] Loaded
2013-01-29T19:46:28.735Z,1359488788.735 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-01-29T19:46:28.748Z,1359488788.748 [Depth_Keller] Loaded
2013-01-29T19:46:28.749Z,1359488788.749 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-01-29T19:46:28.911Z,1359488788.911 [DVL_micro] Loaded
2013-01-29T19:46:28.912Z,1359488788.912 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-01-29T19:46:28.913Z,1359488788.913 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407274E0
2013-01-29T19:46:28.964Z,1359488788.964 [Onboard] Loaded
2013-01-29T19:46:28.964Z,1359488788.964 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-01-29T19:46:28.971Z,1359488788.971 [Radio_Freewave] Loaded
2013-01-29T19:46:28.972Z,1359488788.972 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-01-29T19:46:29.054Z,1359488789.054 [DAT] Loaded
2013-01-29T19:46:29.054Z,1359488789.054 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-01-29T19:46:29.054Z,1359488789.054 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-01-29T19:46:29.055Z,1359488789.055 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-01-29T19:46:29.110Z,1359488789.110 [PAR_Licor] Loaded
2013-01-29T19:46:29.111Z,1359488789.111 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-01-29T19:46:29.112Z,1359488789.112 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-01-29T19:46:29.114Z,1359488789.114 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-01-29T19:46:29.115Z,1359488789.115 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-01-29T19:46:29.121Z,1359488789.121 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-01-29T19:46:29.123Z,1359488789.122 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407794E0
2013-01-29T19:46:29.127Z,1359488789.127 [Supervisor](DEBUG): Running supervisor.
2013-01-29T19:46:29.128Z,1359488789.128 [CommandLine](INFO): Thread ID is 7012
2013-01-29T19:46:29.132Z,1359488789.132 [controlThread](INFO): Thread ID is 7011
2013-01-29T19:46:29.132Z,1359488789.132 [controlThread](DEBUG): Initializing ControlThread
2013-01-29T19:46:29.132Z,1359488789.132 [CycleStarter](INFO): Thread ID is 7010
2013-01-29T19:46:29.133Z,1359488789.133 [InternalSim](DEBUG):  InternalSim initializing...
2013-01-29T19:46:29.167Z,1359488789.167 [logger](INFO): Thread ID is 7013
2013-01-29T19:46:29.194Z,1359488789.194 [SBIT](INFO): Initialize SBIT Component.
2013-01-29T19:46:29.195Z,1359488789.195 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10106
2013-01-29T19:46:29.196Z,1359488789.195 [IBIT](INFO): Initialize IBIT Component.
2013-01-29T19:46:29.196Z,1359488789.196 [CBIT](DEBUG): Initialize CBIT Component.
2013-01-29T19:46:29.197Z,1359488789.197 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-01-29T19:46:29.207Z,1359488789.207 [AsyncPiEstimator](INFO): Thread ID is 7074
2013-01-29T19:46:29.207Z,1359488789.207 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-01-29T19:46:29.221Z,1359488789.221 [DVL_micro](INFO): Thread ID is 7075
2013-01-29T19:46:29.228Z,1359488789.227 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-01-29T19:46:29.228Z,1359488789.228 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-01-29T19:46:29.228Z,1359488789.228 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-01-29T19:46:29.229Z,1359488789.229 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-01-29T19:46:29.229Z,1359488789.229 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-01-29T19:46:29.231Z,1359488789.231 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-01-29T19:46:29.231Z,1359488789.231 [Navigation](DEBUG): Initializing Navigation.
2013-01-29T19:46:29.232Z,1359488789.232 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-01-29T19:46:29.234Z,1359488789.234 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-01-29T19:46:29.235Z,1359488789.234 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-01-29T19:46:29.235Z,1359488789.235 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-01-29T19:46:29.242Z,1359488789.241 [DVL_micro](INFO): Initializing
2013-01-29T19:46:29.242Z,1359488789.242 [DVL_micro](INFO): start:Powering up
2013-01-29T19:46:29.243Z,1359488789.243 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-01-29T19:46:29.243Z,1359488789.243 [DVL_micro](INFO): Cycling power to configure device.
2013-01-29T19:46:29.251Z,1359488789.251 [NavChartDb](INFO): Thread ID is 7076
2013-01-29T19:46:29.253Z,1359488789.253 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-01-29T19:46:29.254Z,1359488789.254 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-01-29T19:46:29.254Z,1359488789.254 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-01-29T19:46:29.254Z,1359488789.254 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-01-29T19:46:29.255Z,1359488789.255 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-01-29T19:46:30.823Z,1359488790.823 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-01-29T19:46:30.863Z,1359488790.864 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-01-29T19:46:30.911Z,1359488790.911 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-01-29T19:46:30.935Z,1359488790.935 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-01-29T19:46:30.936Z,1359488790.936 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-01-29T19:46:31.020Z,1359488791.020 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-01-29T19:46:31.032Z,1359488791.032 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-01-29T19:46:31.035Z,1359488791.035 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-01-29T19:46:31.055Z,1359488791.055 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-01-29T19:46:31.058Z,1359488791.058 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-01-29T19:46:31.064Z,1359488791.065 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-01-29T19:46:31.127Z,1359488791.127 [Default:D.SetSpeed](DEBUG): Construct.
2013-01-29T19:46:31.131Z,1359488791.131 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-01-29T19:46:31.135Z,1359488791.135 [Default:F.Wait](DEBUG): Construct Wait.
2013-01-29T19:46:31.139Z,1359488791.139 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

    <Aggregate Id="GPS" >

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

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium" >

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

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

        <Call RefId="Iridium"/>

    </Aggregate>

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

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

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

</Mission>


2013-01-29T19:46:31.154Z,1359488791.154 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,Onboard,Radio_Freewave,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-01-29T19:46:31.206Z,1359488791.206 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-01-29T19:46:31.322Z,1359488791.322 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-01-29T19:46:31.323Z,1359488791.323 [DVL_micro](INFO): Querying output modes
2013-01-29T19:46:31.323Z,1359488791.323 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-01-29T19:46:31.334Z,1359488791.334 [DVL_micro](DEBUG): cmdResponse: 01
2013-01-29T19:46:31.335Z,1359488791.335 [DVL_micro](INFO): NQ1 output enabled
2013-01-29T19:46:31.335Z,1359488791.335 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-01-29T19:46:31.346Z,1359488791.346 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-01-29T19:46:31.351Z,1359488791.351 [DVL_micro](INFO): pause:Powering down
2013-01-29T19:46:31.403Z,1359488791.402 [Radio_Freewave](INFO): Powering up
2013-01-29T19:46:31.408Z,1359488791.408 [DAT](INFO): Powering up
2013-01-29T19:46:31.408Z,1359488791.408 [DAT](DEBUG): Initializing DAT.
2013-01-29T19:46:31.727Z,1359488791.727 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-01-29T19:46:31.731Z,1359488791.731 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-01-29T19:46:31.745Z,1359488791.745 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-01-29T19:46:31.750Z,1359488791.750 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-01-29T19:46:31.757Z,1359488791.757 [MassServo](DEBUG): Initializing EZServoServo.
2013-01-29T19:46:31.762Z,1359488791.762 [MassServo](DEBUG): Initializing MassServo.
2013-01-29T19:46:31.768Z,1359488791.768 [RudderServo](DEBUG): Initializing EZServoServo.
2013-01-29T19:46:31.802Z,1359488791.802 [RudderServo](DEBUG): Initializing RudderServo.
2013-01-29T19:46:31.808Z,1359488791.808 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-01-29T19:46:31.814Z,1359488791.814 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-01-29T19:46:44.784Z,1359488804.784 [SBIT](IMPORTANT): Beginning Startup BIT
2013-01-29T19:46:44.787Z,1359488804.787 [CBIT](IMPORTANT): Beginning GF scan
2013-01-29T19:46:51.497Z,1359488811.497 [DAT](INFO): Powering down
2013-01-29T19:47:03.660Z,1359488823.660 [CommandLine](IMPORTANT): got command @ --systohc
2013-01-29T19:47:11.243Z,1359488831.243 [CBIT](IMPORTANT): No ground fault detected
2013-01-29T19:47:24.402Z,1359488844.402 [CommandLine](IMPORTANT): got command @ hwclock --systohc
2013-01-29T19:47:38.604Z,1359488858.604 [SBIT](IMPORTANT): SBIT PASSED
2013-01-29T19:47:38.982Z,1359488858.982 [MissionManager](IMPORTANT): Started mission Startup
2013-01-29T19:47:38.982Z,1359488858.982 [Startup] Running Loop=1
2013-01-29T19:47:38.982Z,1359488858.982 [Startup](INFO): Aggregate::initialize Startup
2013-01-29T19:47:38.982Z,1359488858.982 [Startup:A.GoToSurface] Running Loop=1
2013-01-29T19:47:38.983Z,1359488858.983 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-01-29T19:47:43.911Z,1359488863.911 [CommandLine](INFO): End of History
2013-01-29T19:47:44.800Z,1359488864.800 [CommandLine](INFO): End of History
2013-01-29T19:47:44.802Z,1359488864.802 [CommandLine](INFO): End of History
2013-01-29T19:47:44.803Z,1359488864.803 [CommandLine](INFO): End of History
2013-01-29T19:47:44.805Z,1359488864.805 [CommandLine](INFO): End of History
2013-01-29T19:47:44.838Z,1359488864.838 [CommandLine](INFO): End of History
2013-01-29T19:47:45.040Z,1359488865.040 [CommandLine](INFO): End of History
2013-01-29T19:47:45.255Z,1359488865.255 [CommandLine](INFO): End of History
2013-01-29T19:47:45.483Z,1359488865.483 [CommandLine](INFO): End of History
2013-01-29T19:47:45.710Z,1359488865.710 [CommandLine](INFO): End of History
2013-01-29T19:47:46.165Z,1359488866.165 [CommandLine](INFO): End of History
2013-01-29T19:47:46.397Z,1359488866.397 [CommandLine](INFO): End of History
2013-01-29T19:47:46.650Z,1359488866.650 [CommandLine](INFO): End of History
2013-01-29T19:49:33.030Z,1359488973.030 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:49:33.031Z,1359488973.031 [CommandLine](IMPORTANT): platform_pitch_angle 7.624512 degree
2013-01-29T19:49:36.325Z,1359488976.325 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:49:36.344Z,1359488976.344 [CommandLine](IMPORTANT): platform_pitch_angle 8.854981 degree
2013-01-29T19:49:38.280Z,1359488978.280 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:49:38.281Z,1359488978.281 [CommandLine](IMPORTANT): platform_pitch_angle 9.426270 degree
2013-01-29T19:50:42.693Z,1359489042.693 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 2.300000 centimeter
2013-01-29T19:50:42.695Z,1359489042.695 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2013-01-29T19:50:43.025Z,1359489043.025 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,Onboard,Radio_Freewave,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-01-29T19:50:48.911Z,1359489048.911 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:50:48.911Z,1359489048.911 [CommandLine](IMPORTANT): platform_pitch_angle 16.721191 degree
2013-01-29T19:50:53.276Z,1359489053.276 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:50:53.277Z,1359489053.277 [CommandLine](IMPORTANT): platform_pitch_angle 14.436035 degree
2013-01-29T19:50:55.689Z,1359489055.689 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:50:55.690Z,1359489055.690 [CommandLine](IMPORTANT): platform_pitch_angle 11.667480 degree
2013-01-29T19:50:57.363Z,1359489057.363 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:50:57.364Z,1359489057.364 [CommandLine](IMPORTANT): platform_pitch_angle 9.645996 degree
2013-01-29T19:50:58.889Z,1359489058.889 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:50:58.889Z,1359489058.889 [CommandLine](IMPORTANT): platform_pitch_angle 7.888184 degree
2013-01-29T19:51:00.640Z,1359489060.640 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:51:00.640Z,1359489060.640 [CommandLine](IMPORTANT): platform_pitch_angle 6.328125 degree
2013-01-29T19:51:02.194Z,1359489062.194 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:51:02.195Z,1359489062.195 [CommandLine](IMPORTANT): platform_pitch_angle 5.888672 degree
2013-01-29T19:51:03.514Z,1359489063.514 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:51:03.515Z,1359489063.515 [CommandLine](IMPORTANT): platform_pitch_angle 5.603027 degree
2013-01-29T19:51:17.312Z,1359489077.312 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:51:17.313Z,1359489077.313 [CommandLine](IMPORTANT): platform_pitch_angle -0.285645 degree
2013-01-29T19:51:26.375Z,1359489086.375 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T19:51:26.376Z,1359489086.376 [CommandLine](IMPORTANT): platform_pitch_angle -3.054199 degree
2013-01-29T19:52:42.670Z,1359489162.670 [VerticalControl](CRITICAL): Failure to ascend, stopping mission after 300.323792 seconds, depthRate=-0.000001 m/s, pitch=-3.449707 deg.
2013-01-29T19:57:43.069Z,1359489463.069 [VerticalControl](CRITICAL): Failure to ascend, dropping drop weight after 300.398407 seconds, depthRate=0.000436 m/s, pitch=-3.515625 deg.
2013-01-29T20:00:50.238Z,1359489650.238 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:00:50.239Z,1359489650.239 [CommandLine](IMPORTANT): platform_pitch_angle -3.098145 degree
2013-01-29T20:01:01.750Z,1359489661.750 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:01.750Z,1359489661.750 [CommandLine](IMPORTANT): platform_pitch_angle -3.142090 degree
2013-01-29T20:01:03.489Z,1359489663.489 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:03.490Z,1359489663.490 [CommandLine](IMPORTANT): platform_pitch_angle -3.076172 degree
2013-01-29T20:01:05.596Z,1359489665.596 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:05.597Z,1359489665.597 [CommandLine](IMPORTANT): platform_pitch_angle -3.120117 degree
2013-01-29T20:01:07.449Z,1359489667.449 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:07.450Z,1359489667.450 [CommandLine](IMPORTANT): platform_pitch_angle -3.032227 degree
2013-01-29T20:01:09.232Z,1359489669.232 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:09.233Z,1359489669.233 [CommandLine](IMPORTANT): platform_pitch_angle -3.142090 degree
2013-01-29T20:01:10.820Z,1359489670.820 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:10.821Z,1359489670.820 [CommandLine](IMPORTANT): platform_pitch_angle -3.054199 degree
2013-01-29T20:01:12.696Z,1359489672.696 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:12.697Z,1359489672.697 [CommandLine](IMPORTANT): platform_pitch_angle -3.164063 degree
2013-01-29T20:01:14.270Z,1359489674.270 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2013-01-29T20:01:14.271Z,1359489674.271 [CommandLine](IMPORTANT): platform_pitch_angle -3.076172 degree
2013-01-29T20:02:06.176Z,1359489726.176 [CommandLine](IMPORTANT): got command report periodic 1.000000 platform_pitch_angle
2013-01-29T20:02:06.342Z,1359489726.342 [Reporter](INFO): platform_pitch_angle -3.032227 arcdeg
2013-01-29T20:02:07.549Z,1359489727.549 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:08.742Z,1359489728.742 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:09.946Z,1359489729.946 [Reporter](INFO): platform_pitch_angle -3.142090 arcdeg
2013-01-29T20:02:11.183Z,1359489731.183 [Reporter](INFO): platform_pitch_angle -3.054199 arcdeg
2013-01-29T20:02:12.345Z,1359489732.345 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:13.542Z,1359489733.542 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg
2013-01-29T20:02:14.742Z,1359489734.742 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:15.993Z,1359489735.993 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:17.146Z,1359489737.146 [Reporter](INFO): platform_pitch_angle -3.164063 arcdeg
2013-01-29T20:02:18.346Z,1359489738.346 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg
2013-01-29T20:02:19.542Z,1359489739.542 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg
2013-01-29T20:02:20.842Z,1359489740.842 [Reporter](INFO): platform_pitch_angle -3.032227 arcdeg
2013-01-29T20:02:21.942Z,1359489741.942 [Reporter](INFO): platform_pitch_angle -3.142090 arcdeg
2013-01-29T20:02:23.146Z,1359489743.146 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:24.346Z,1359489744.346 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:25.548Z,1359489745.548 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:26.742Z,1359489746.742 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:27.942Z,1359489747.942 [Reporter](INFO): platform_pitch_angle -3.054199 arcdeg
2013-01-29T20:02:29.142Z,1359489749.142 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg
2013-01-29T20:02:30.345Z,1359489750.345 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:31.538Z,1359489751.538 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:32.742Z,1359489752.742 [Reporter](INFO): platform_pitch_angle -3.032227 arcdeg
2013-01-29T20:02:33.982Z,1359489753.982 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg
2013-01-29T20:02:35.145Z,1359489755.145 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg
2013-01-29T20:02:36.394Z,1359489756.394 [Reporter](INFO): platform_pitch_angle -3.054199 arcdeg
2013-01-29T20:02:37.542Z,1359489757.542 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:38.742Z,1359489758.742 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:39.946Z,1359489759.946 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:41.194Z,1359489761.194 [Reporter](INFO): platform_pitch_angle -3.054199 arcdeg
2013-01-29T20:02:42.346Z,1359489762.346 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg
2013-01-29T20:02:43.586Z,1359489763.586 [Reporter](INFO): platform_pitch_angle -3.186035 arcdeg
2013-01-29T20:02:44.742Z,1359489764.742 [Reporter](INFO): platform_pitch_angle -3.142090 arcdeg
2013-01-29T20:02:45.942Z,1359489765.942 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:47.146Z,1359489767.146 [Reporter](INFO): platform_pitch_angle -3.054199 arcdeg
2013-01-29T20:02:48.345Z,1359489768.345 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:49.548Z,1359489769.548 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:50.746Z,1359489770.746 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:51.942Z,1359489771.942 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:53.186Z,1359489773.186 [Reporter](INFO): platform_pitch_angle -3.076172 arcdeg
2013-01-29T20:02:54.345Z,1359489774.345 [Reporter](INFO): platform_pitch_angle -3.098145 arcdeg
2013-01-29T20:02:55.542Z,1359489775.542 [Reporter](INFO): platform_pitch_angle -3.120117 arcdeg