2012-09-20T23:46:19.075Z,1348184779.075 [Supervisor](DEBUG): Initializing supervisor.
2012-09-20T23:46:19.078Z,1348184779.078 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2012-09-20T23:46:19.079Z,1348184779.079 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-09-20T23:46:19.082Z,1348184779.082 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2012-09-20T23:46:19.086Z,1348184779.086 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-09-20T23:46:19.097Z,1348184779.097 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-09-20T23:46:19.098Z,1348184779.098 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2012-09-20T23:46:19.099Z,1348184779.099 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-09-20T23:46:19.100Z,1348184779.100 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-09-20T23:46:19.102Z,1348184779.102 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-09-20T23:46:19.418Z,1348184779.418 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-09-20T23:46:19.420Z,1348184779.420 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-09-20T23:46:19.622Z,1348184779.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-09-20T23:46:19.622Z,1348184779.622 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-09-20T23:46:19.718Z,1348184779.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-09-20T23:46:19.720Z,1348184779.720 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-09-20T23:46:19.939Z,1348184779.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-09-20T23:46:19.940Z,1348184779.940 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-09-20T23:46:20.090Z,1348184780.090 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-09-20T23:46:20.092Z,1348184780.092 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-09-20T23:46:20.355Z,1348184780.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-09-20T23:46:20.356Z,1348184780.356 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-09-20T23:46:20.546Z,1348184780.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-09-20T23:46:20.548Z,1348184780.548 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-09-20T23:46:20.840Z,1348184780.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-09-20T23:46:20.842Z,1348184780.842 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-09-20T23:46:20.959Z,1348184780.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-09-20T23:46:20.960Z,1348184780.960 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-09-20T23:46:21.432Z,1348184781.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-09-20T23:46:21.432Z,1348184781.432 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-09-20T23:46:21.551Z,1348184781.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-09-20T23:46:21.552Z,1348184781.552 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-09-20T23:46:21.647Z,1348184781.647 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-09-20T23:46:21.651Z,1348184781.651 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-09-20T23:46:21.762Z,1348184781.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-09-20T23:46:21.908Z,1348184781.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-09-20T23:46:22.002Z,1348184782.002 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-09-20T23:46:22.114Z,1348184782.114 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-09-20T23:46:22.228Z,1348184782.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-09-20T23:46:22.364Z,1348184782.364 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-09-20T23:46:22.466Z,1348184782.466 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-09-20T23:46:22.615Z,1348184782.615 [Supervisor](FAULT): Ignoring configuration overrides from Data/config.db
2012-09-20T23:46:22.712Z,1348184782.712 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-09-20T23:46:22.905Z,1348184782.905 [InternalSim] Loaded
2012-09-20T23:46:22.905Z,1348184782.905 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-09-20T23:46:22.906Z,1348184782.906 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-09-20T23:46:22.906Z,1348184782.906 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-09-20T23:46:24.303Z,1348184784.303 [SBIT](DEBUG): Construct Startup Built In Test.
2012-09-20T23:46:24.339Z,1348184784.339 [SBIT] Loaded
2012-09-20T23:46:24.340Z,1348184784.340 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-09-20T23:46:24.341Z,1348184784.341 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-09-20T23:46:24.368Z,1348184784.368 [IBIT] Loaded
2012-09-20T23:46:24.368Z,1348184784.368 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-09-20T23:46:24.372Z,1348184784.372 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-09-20T23:46:24.605Z,1348184784.605 [CBIT] Loaded
2012-09-20T23:46:24.605Z,1348184784.605 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-09-20T23:46:24.606Z,1348184784.606 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-09-20T23:46:24.606Z,1348184784.606 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-09-20T23:46:24.861Z,1348184784.861 [BuoyancyServo] Loaded
2012-09-20T23:46:24.861Z,1348184784.861 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-09-20T23:46:24.891Z,1348184784.891 [RudderServo] Loaded
2012-09-20T23:46:24.891Z,1348184784.891 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-09-20T23:46:24.915Z,1348184784.915 [ThrusterServo] Loaded
2012-09-20T23:46:24.915Z,1348184784.915 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-09-20T23:46:24.915Z,1348184784.915 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-09-20T23:46:24.916Z,1348184784.916 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-09-20T23:46:24.952Z,1348184784.952 [DepthRateCalculator] Loaded
2012-09-20T23:46:24.952Z,1348184784.953 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-09-20T23:46:28.809Z,1348184788.809 [HFRadarModelCalc] Loaded
2012-09-20T23:46:28.810Z,1348184788.810 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2012-09-20T23:46:28.829Z,1348184788.829 [NavChart] Loaded
2012-09-20T23:46:28.830Z,1348184788.829 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-09-20T23:46:28.835Z,1348184788.835 [PitchRateCalculator] Loaded
2012-09-20T23:46:28.836Z,1348184788.836 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-09-20T23:46:28.842Z,1348184788.842 [SpeedCalculator] Loaded
2012-09-20T23:46:28.842Z,1348184788.842 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-09-20T23:46:28.861Z,1348184788.861 [TempGradientCalculator] Loaded
2012-09-20T23:46:28.861Z,1348184788.861 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-09-20T23:46:28.867Z,1348184788.867 [YawRateCalculator] Loaded
2012-09-20T23:46:28.867Z,1348184788.867 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-09-20T23:46:28.887Z,1348184788.887 [Navigation] Loaded
2012-09-20T23:46:28.887Z,1348184788.887 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-09-20T23:46:28.888Z,1348184788.888 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-09-20T23:46:28.888Z,1348184788.888 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-09-20T23:46:29.166Z,1348184789.166 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-09-20T23:46:29.167Z,1348184789.167 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-09-20T23:46:29.207Z,1348184789.207 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-09-20T23:46:29.208Z,1348184789.208 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-09-20T23:46:29.271Z,1348184789.270 [VerticalControl](DEBUG): Construct VerticalControl.
2012-09-20T23:46:29.321Z,1348184789.321 [VerticalControl] Loaded
2012-09-20T23:46:29.321Z,1348184789.321 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-09-20T23:46:29.322Z,1348184789.322 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-09-20T23:46:29.347Z,1348184789.348 [HorizontalControl] Loaded
2012-09-20T23:46:29.348Z,1348184789.348 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-09-20T23:46:29.349Z,1348184789.349 [SpeedControl](DEBUG): Construct SpeedControl.
2012-09-20T23:46:29.350Z,1348184789.351 [SpeedControl] Loaded
2012-09-20T23:46:29.351Z,1348184789.351 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-09-20T23:46:29.352Z,1348184789.352 [LoopControl](DEBUG): Construct LoopControl.
2012-09-20T23:46:29.352Z,1348184789.352 [LoopControl] Loaded
2012-09-20T23:46:29.352Z,1348184789.352 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-09-20T23:46:29.353Z,1348184789.353 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-09-20T23:46:29.354Z,1348184789.354 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-09-20T23:46:29.363Z,1348184789.364 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-09-20T23:46:29.368Z,1348184789.368 [AsyncPiEstimator] Loaded
2012-09-20T23:46:29.368Z,1348184789.368 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-09-20T23:46:29.370Z,1348184789.370 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4060A4E0
2012-09-20T23:46:29.371Z,1348184789.371 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-09-20T23:46:29.372Z,1348184789.372 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-09-20T23:46:29.546Z,1348184789.546 [AHRS_sp3003D] Loaded
2012-09-20T23:46:29.546Z,1348184789.546 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-09-20T23:46:29.559Z,1348184789.559 [Depth_Keller] Loaded
2012-09-20T23:46:29.560Z,1348184789.560 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-09-20T23:46:29.565Z,1348184789.565 [DropWeight] Loaded
2012-09-20T23:46:29.565Z,1348184789.565 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-09-20T23:46:29.699Z,1348184789.699 [DVL_micro] Loaded
2012-09-20T23:46:29.699Z,1348184789.699 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2012-09-20T23:46:29.702Z,1348184789.703 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 4068A4E0
2012-09-20T23:46:29.793Z,1348184789.793 [NAL9602] Loaded
2012-09-20T23:46:29.794Z,1348184789.793 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2012-09-20T23:46:29.848Z,1348184789.848 [Onboard] Loaded
2012-09-20T23:46:29.848Z,1348184789.848 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-09-20T23:46:29.859Z,1348184789.859 [Radio_Freewave] Loaded
2012-09-20T23:46:29.859Z,1348184789.859 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-09-20T23:46:29.860Z,1348184789.860 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-09-20T23:46:29.860Z,1348184789.861 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-09-20T23:46:29.962Z,1348184789.962 [CTD_NeilBrown] Loaded
2012-09-20T23:46:29.963Z,1348184789.963 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-09-20T23:46:29.966Z,1348184789.966 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406E24E0
2012-09-20T23:46:29.977Z,1348184789.977 [PAR_Licor] Loaded
2012-09-20T23:46:29.977Z,1348184789.977 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2012-09-20T23:46:29.999Z,1348184789.999 [Turbulence_NPS] Loaded
2012-09-20T23:46:29.999Z,1348184789.999 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread.
2012-09-20T23:46:30.002Z,1348184790.002 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 407124E0
2012-09-20T23:46:30.038Z,1348184790.038 [WetLabsBB2FL] Loaded
2012-09-20T23:46:30.039Z,1348184790.039 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2012-09-20T23:46:30.042Z,1348184790.042 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407424E0
2012-09-20T23:46:30.043Z,1348184790.043 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-09-20T23:46:30.045Z,1348184790.045 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-09-20T23:46:30.046Z,1348184790.046 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-09-20T23:46:30.052Z,1348184790.052 [NavChartDb](CRITICAL): No configuration setting for: NavChartDb.cycleTimeout
2012-09-20T23:46:30.053Z,1348184790.053 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-09-20T23:46:30.058Z,1348184790.058 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407724E0
2012-09-20T23:46:30.063Z,1348184790.063 [Supervisor](DEBUG): Running supervisor.
2012-09-20T23:46:30.064Z,1348184790.064 [CommandLine](INFO): Thread ID is 750
2012-09-20T23:46:30.067Z,1348184790.067 [controlThread](INFO): Thread ID is 749
2012-09-20T23:46:30.067Z,1348184790.067 [controlThread](DEBUG): Initializing ControlThread
2012-09-20T23:46:30.068Z,1348184790.068 [CycleStarter](INFO): Thread ID is 748
2012-09-20T23:46:30.068Z,1348184790.068 [InternalSim](DEBUG):  InternalSim initializing...
2012-09-20T23:46:30.182Z,1348184790.182 [AsyncPiEstimator](INFO): Thread ID is 816
2012-09-20T23:46:30.182Z,1348184790.182 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-09-20T23:46:30.261Z,1348184790.261 [DVL_micro](INFO): Thread ID is 817
2012-09-20T23:46:30.377Z,1348184790.378 [CTD_NeilBrown](INFO): Thread ID is 818
2012-09-20T23:46:30.378Z,1348184790.378 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-09-20T23:46:30.470Z,1348184790.470 [Turbulence_NPS](INFO): Thread ID is 819
2012-09-20T23:46:30.471Z,1348184790.471 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS.
2012-09-20T23:46:30.481Z,1348184790.481 [SBIT](INFO): Initialize SBIT Component.
2012-09-20T23:46:30.482Z,1348184790.482 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9861
2012-09-20T23:46:30.483Z,1348184790.483 [IBIT](INFO): Initialize IBIT Component.
2012-09-20T23:46:30.484Z,1348184790.484 [CBIT](DEBUG): Initialize CBIT Component.
2012-09-20T23:46:30.484Z,1348184790.484 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2012-09-20T23:46:30.484Z,1348184790.484 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-09-20T23:46:30.485Z,1348184790.485 [WetLabsBB2FL](INFO): Thread ID is 820
2012-09-20T23:46:30.486Z,1348184790.486 [WetLabsBB2FL](INFO): Powering down
2012-09-20T23:46:30.495Z,1348184790.495 [NavChartDb](INFO): Thread ID is 821
2012-09-20T23:46:30.535Z,1348184790.535 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-09-20T23:46:30.535Z,1348184790.535 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-09-20T23:46:30.536Z,1348184790.536 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-09-20T23:46:30.536Z,1348184790.536 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-09-20T23:46:30.536Z,1348184790.536 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-09-20T23:46:30.538Z,1348184790.538 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-09-20T23:46:30.538Z,1348184790.538 [Navigation](DEBUG): Initializing Navigation.
2012-09-20T23:46:30.538Z,1348184790.538 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-09-20T23:46:30.540Z,1348184790.540 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-09-20T23:46:30.541Z,1348184790.541 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-09-20T23:46:30.541Z,1348184790.541 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-09-20T23:46:30.555Z,1348184790.556 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-09-20T23:46:30.616Z,1348184790.616 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-09-20T23:46:30.630Z,1348184790.630 [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>


2012-09-20T23:46:30.631Z,1348184790.631 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-09-20T23:46:30.775Z,1348184790.775 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-09-20T23:46:30.777Z,1348184790.777 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-09-20T23:46:30.780Z,1348184790.780 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-09-20T23:46:30.788Z,1348184790.788 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-09-20T23:46:30.799Z,1348184790.799 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-09-20T23:46:30.806Z,1348184790.806 [Default:Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-09-20T23:46:30.815Z,1348184790.815 [Default:D.SetSpeed](DEBUG): Construct.
2012-09-20T23:46:30.818Z,1348184790.818 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-09-20T23:46:30.823Z,1348184790.823 [Default:F.Wait](DEBUG): Construct Wait.
2012-09-20T23:46:30.826Z,1348184790.826 [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>


2012-09-20T23:46:30.830Z,1348184790.830 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger,
2012-09-20T23:46:30.855Z,1348184790.855 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-09-20T23:46:31.091Z,1348184791.091 [Depth_Keller](INFO): A/D timeout, 2 tries over 221 ms

2012-09-20T23:46:31.091Z,1348184791.091 [Depth_Keller] Data Fault, FailCount= 1
2012-09-20T23:46:31.091Z,1348184791.091 [Depth_Keller](ERROR): Data Fault
2012-09-20T23:46:31.143Z,1348184791.143 [DVL_micro](INFO): Initializing
2012-09-20T23:46:31.143Z,1348184791.143 [DVL_micro](INFO): start:Powering up
2012-09-20T23:46:31.147Z,1348184791.147 [Radio_Freewave](INFO): Powering up
2012-09-20T23:46:31.439Z,1348184791.439 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-09-20T23:46:31.441Z,1348184791.441 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-09-20T23:46:31.448Z,1348184791.448 [RudderServo](DEBUG): Initializing EZServoServo.
2012-09-20T23:46:31.451Z,1348184791.451 [RudderServo](DEBUG): Initializing RudderServo.
2012-09-20T23:46:31.465Z,1348184791.465 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-09-20T23:46:31.466Z,1348184791.466 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-09-20T23:46:31.497Z,1348184791.497 [CBIT](ERROR): Data Fault in component: Depth_Keller
2012-09-20T23:46:31.497Z,1348184791.497 [CBIT](INFO): Clearing failed state for component Depth_Keller
2012-09-20T23:46:31.497Z,1348184791.497 [Depth_Keller] No Fault, FailCount= 1
2012-09-20T23:46:35.093Z,1348184795.093 [NAL9602](INFO): Powering up NAL9602
2012-09-20T23:46:35.171Z,1348184795.171 [PAR_Licor](ERROR): PAR reading out of range: -0.020663 uMol/s/m2
2012-09-20T23:46:39.569Z,1348184799.569 [PAR_Licor](ERROR): PAR reading out of range: -0.001589 uMol/s/m2